You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@zookeeper.apache.org by André Oriani <ra...@students.ic.unicamp.br> on 2011/04/07 05:10:22 UTC

Understanding better the Fast Leader Election algorithm

Hi all,

I am trying to extract a minimalistic version of the Zab protocol from
Zookeeper (https://github.com/aoriani/zab, btw) . I doing that by bringing
one class at time, starting from QuorumCnxManager.  I brought enough classes
to run the Fast Leader Election . Some classes I had to stub. Consequently
 the only zxid possible now is zero.

I am not sure if I understood  the election algorithm .  I have three peers.
 I start each one sequentially. So when 2  runs, it connects to 1. Both
agree that 2 had won, because it has the greatest id so far and it has
quorum. Thus 2 goes to leading state and 1 goes to following state. But then
2 becomes alive. It connects to 1 and 2. Having received votes from all
peers including itself  and having the biggest id , it also goes to leading
state.

So we have 2 peers in the leading state. Is this wrong ? Or it is because I
have not yet implement ( copied ) the NEW LEADER proposal? If so , how the
election proceeds from this point ?

I have added some logs bellow in case someone wants to take a look.


Thanks and Regards,
André







Peer 1

[2011-04-05 21:35:30,569] INFO     0[main] -
org.apache.zookeeper.server.quorum.QuorumPeerConfig.parse(QuorumPeerConfig.java:93)
- Reading configuration from: conf/zoo1.cfg
[2011-04-05 21:35:30,663] INFO    94[main] -
org.apache.zookeeper.server.quorum.QuorumPeerConfig.parseProperties(QuorumPeerConfig.java:314)
- Defaulting to majority quorums
[2011-04-05 21:35:30,684] INFO   115[main] -
org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:119)
- Starting quorum peer
[2011-04-05 21:35:30,712] INFO   143[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setTickTime(QuorumPeer.java:822)
- tickTime set to 2000
[2011-04-05 21:35:30,730] INFO   161[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setMinSessionTimeout(QuorumPeer.java:842)
- minSessionTimeout set to -1
[2011-04-05 21:35:30,730] INFO   161[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setMaxSessionTimeout(QuorumPeer.java:853)
- maxSessionTimeout set to -1
[2011-04-05 21:35:30,730] INFO   161[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setInitLimit(QuorumPeer.java:868)
- initLimit set to 5
[2011-04-05 21:35:30,820] INFO   251[Thread-2] -
org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:490)
- My election bind port: 0.0.0.0/0.0.0.0:1444
[2011-04-05 21:35:30,823]DEBUG   254[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:586) -
Starting quorum peer
[2011-04-05 21:35:30,823] INFO   254[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:622) -
LOOKING
[2011-04-05 21:35:30,824]DEBUG   255[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumPeer.makeLEStrategy(QuorumPeer.java:553)
- Initializing leader election protocol...
[2011-04-05 21:35:30,824] INFO   255[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:655)
- New election. My id =  1, Proposed zxid = 0
[2011-04-05 21:35:30,856]DEBUG   287[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 2
[2011-04-05 21:35:30,857]DEBUG   288[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 1
[2011-04-05 21:35:30,867] INFO   298[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 1 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
(n.sid), LOOKING (my state)
[2011-04-05 21:35:30,867]DEBUG   298[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
- id: 1, proposed id: 1, zxid: 0, proposed zxid: 0
[2011-04-05 21:35:30,870]DEBUG   301[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
- Adding vote: From = 1, Proposed leader = 1, Porposed zxid = 0, Proposed
epoch = 1
[2011-04-05 21:35:30,932] WARN   363[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
- Cannot open channel to 2 at election address /127.0.0.1:2444
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
 at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
at java.net.Socket.connect(Socket.java:529)
 at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:327)
 at
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:360)
at
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:333)
 at java.lang.Thread.run(Thread.java:680)
[2011-04-05 21:35:30,939]DEBUG   370[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 3
[2011-04-05 21:35:30,939] WARN   370[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
- Cannot open channel to 3 at election address /127.0.0.1:3444
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
 at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
at java.net.Socket.connect(Socket.java:529)
 at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:327)
 at
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:360)
at
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:333)
 at java.lang.Thread.run(Thread.java:680)
[2011-04-05 21:35:31,072]DEBUG   503[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
- Queue size: 1
[2011-04-05 21:35:31,073]DEBUG   504[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
- Queue size: 1
[2011-04-05 21:35:31,073]DEBUG   504[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 2
[2011-04-05 21:35:31,074] WARN   505[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
- Cannot open channel to 2 at election address /127.0.0.1:2444
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
 at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
at java.net.Socket.connect(Socket.java:529)
 at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
 at
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
[2011-04-05 21:35:31,074]DEBUG   505[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 3
[2011-04-05 21:35:31,075] WARN   506[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
- Cannot open channel to 3 at election address /127.0.0.1:3444
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
 at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
at java.net.Socket.connect(Socket.java:529)
 at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
 at
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
[2011-04-05 21:35:31,075] INFO   506[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:689)
- Notification time out: 400
[2011-04-05 21:35:31,476]DEBUG   907[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
- Queue size: 1
[2011-04-05 21:35:31,476]DEBUG   907[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
- Queue size: 1
[2011-04-05 21:35:31,477]DEBUG   908[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 2
[2011-04-05 21:35:31,477] WARN   908[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
- Cannot open channel to 2 at election address /127.0.0.1:2444
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
 at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
at java.net.Socket.connect(Socket.java:529)
 at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
 at
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
[2011-04-05 21:35:31,478]DEBUG   909[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 3
[2011-04-05 21:35:31,478] WARN   909[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
- Cannot open channel to 3 at election address /127.0.0.1:3444
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
 at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
at java.net.Socket.connect(Socket.java:529)
 at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
 at
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
[2011-04-05 21:35:31,479] INFO   910[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:689)
- Notification time out: 800
[2011-04-05 21:35:32,279]DEBUG  1710[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
- Queue size: 1
[2011-04-05 21:35:32,280]DEBUG  1711[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
- Queue size: 1
[2011-04-05 21:35:32,280]DEBUG  1711[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 2
[2011-04-05 21:35:32,281] WARN  1712[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
- Cannot open channel to 2 at election address /127.0.0.1:2444
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
 at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
at java.net.Socket.connect(Socket.java:529)
 at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
 at
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
[2011-04-05 21:35:32,281]DEBUG  1712[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 3
[2011-04-05 21:35:32,282] WARN  1713[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
- Cannot open channel to 3 at election address /127.0.0.1:3444
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
 at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
at java.net.Socket.connect(Socket.java:529)
 at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
 at
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
[2011-04-05 21:35:32,282] INFO  1713[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:689)
- Notification time out: 1600
[2011-04-05 21:35:33,883]DEBUG  3314[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
- Queue size: 1
[2011-04-05 21:35:33,883]DEBUG  3314[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
- Queue size: 1
[2011-04-05 21:35:33,883]DEBUG  3314[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 2
[2011-04-05 21:35:33,884] WARN  3315[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
- Cannot open channel to 2 at election address /127.0.0.1:2444
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
 at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
at java.net.Socket.connect(Socket.java:529)
 at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
 at
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
[2011-04-05 21:35:33,884]DEBUG  3315[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 3
[2011-04-05 21:35:33,885] WARN  3316[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
- Cannot open channel to 3 at election address /127.0.0.1:3444
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
 at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
at java.net.Socket.connect(Socket.java:529)
 at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
 at
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
[2011-04-05 21:35:33,885] INFO  3316[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:689)
- Notification time out: 3200
[2011-04-05 21:35:34,897] INFO  4328[/127.0.0.1:1444] -
org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:497)
- Received connection request /127.0.0.1:49494
[2011-04-05 21:35:34,953]DEBUG  4384[/127.0.0.1:1444] -
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.<init>(QuorumCnxManager.java:573)
- Address of remote peer: 2
[2011-04-05 21:35:34,958]DEBUG  4389[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 1
[2011-04-05 21:35:34,958] INFO  4389[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 2
(n.sid), LOOKING (my state)
[2011-04-05 21:35:34,958]DEBUG  4389[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
- id: 2, proposed id: 1, zxid: 0, proposed zxid: 0
[2011-04-05 21:35:34,959] INFO  4390[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:713)
- Updating proposal
[2011-04-05 21:35:34,959]DEBUG  4390[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
- Adding vote: From = 2, Proposed leader = 2, Porposed zxid = 0, Proposed
epoch = 1
[2011-04-05 21:35:34,960]DEBUG  4391[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:377)
- There is a connection already for server 2
[2011-04-05 21:35:34,960]DEBUG  4391[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 3
[2011-04-05 21:35:34,960] WARN  4391[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
- Cannot open channel to 3 at election address /127.0.0.1:3444
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
 at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
at java.net.Socket.connect(Socket.java:529)
 at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:327)
 at
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:360)
at
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:333)
 at java.lang.Thread.run(Thread.java:680)
[2011-04-05 21:35:34,961]DEBUG  4392[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 1
[2011-04-05 21:35:34,962] INFO  4393[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
(n.sid), LOOKING (my state)
[2011-04-05 21:35:34,962]DEBUG  4393[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
- id: 2, proposed id: 2, zxid: 0, proposed zxid: 0
[2011-04-05 21:35:34,962]DEBUG  4393[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
- Adding vote: From = 1, Proposed leader = 2, Porposed zxid = 0, Proposed
epoch = 1
[2011-04-05 21:35:35,162]DEBUG  4593[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.learningState(FastLeaderElection.java:597)
- I'm a participant: 1
[2011-04-05 21:35:35,163]DEBUG  4594[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:763)
- About to leave FLE instance: Leader= 2, Zxid = 0, My id = 1, My state =
FOLLOWING
[2011-04-05 21:35:35,163] INFO  4594[QuorumPeer:24807938] -
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:644) -
FOLLOWING
[2011-04-05 21:35:53,510] INFO 22941[/127.0.0.1:1444] -
org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:497)
- Received connection request /127.0.0.1:49500
[2011-04-05 21:35:53,511]DEBUG 22942[/127.0.0.1:1444] -
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.<init>(QuorumCnxManager.java:573)
- Address of remote peer: 3
[2011-04-05 21:35:53,514]DEBUG 22945[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 1
[2011-04-05 21:35:53,514] INFO 22945[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 3
(n.sid), FOLLOWING (my state)
[2011-04-05 21:35:53,514]DEBUG 22945[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:288)
- Sending new notification. My id =  1, Recipient = 3
[2011-04-05 21:35:53,516]DEBUG 22947[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:377)
- There is a connection already for server 3
[2011-04-05 21:35:30,569] INFO     0[main] -
org.apache.zookeeper.server.quorum.QuorumPeerConfig.parse(QuorumPeerConfig.java:93)
- Reading configuration from: conf/zoo1.cfg
[2011-04-05 21:35:30,663] INFO    94[main] -
org.apache.zookeeper.server.quorum.QuorumPeerConfig.parseProperties(QuorumPeerConfig.java:314)
- Defaulting to majority quorums
[2011-04-05 21:35:30,684] INFO   115[main] -
org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:119)
- Starting quorum peer
[2011-04-05 21:35:30,712] INFO   143[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setTickTime(QuorumPeer.java:822)
- tickTime set to 2000
[2011-04-05 21:35:30,730] INFO   161[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setMinSessionTimeout(QuorumPeer.java:842)
- minSessionTimeout set to -1
[2011-04-05 21:35:30,730] INFO   161[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setMaxSessionTimeout(QuorumPeer.java:853)
- maxSessionTimeout set to -1
[2011-04-05 21:35:30,730] INFO   161[main]



Peer 2

2011-04-05 21:35:34,778] INFO     0[main] -
org.apache.zookeeper.server.quorum.QuorumPeerConfig.parse(QuorumPeerConfig.java:93)
- Reading configuration from: conf/zoo2.cfg
[2011-04-05 21:35:34,824] INFO    46[main] -
org.apache.zookeeper.server.quorum.QuorumPeerConfig.parseProperties(QuorumPeerConfig.java:314)
- Defaulting to majority quorums
[2011-04-05 21:35:34,848] INFO    70[main] -
org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:119)
- Starting quorum peer
[2011-04-05 21:35:34,852] INFO    74[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setTickTime(QuorumPeer.java:822)
- tickTime set to 2000
[2011-04-05 21:35:34,857] INFO    79[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setMinSessionTimeout(QuorumPeer.java:842)
- minSessionTimeout set to -1
[2011-04-05 21:35:34,857] INFO    79[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setMaxSessionTimeout(QuorumPeer.java:853)
- maxSessionTimeout set to -1
[2011-04-05 21:35:34,857] INFO    79[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setInitLimit(QuorumPeer.java:868)
- initLimit set to 5
[2011-04-05 21:35:34,881] INFO   103[Thread-2] -
org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:490)
- My election bind port: 0.0.0.0/0.0.0.0:2444
[2011-04-05 21:35:34,884]DEBUG   106[QuorumPeer:7958910] -
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:586) -
Starting quorum peer
[2011-04-05 21:35:34,884] INFO   106[QuorumPeer:7958910] -
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:622) -
LOOKING
[2011-04-05 21:35:34,885]DEBUG   107[QuorumPeer:7958910] -
org.apache.zookeeper.server.quorum.QuorumPeer.makeLEStrategy(QuorumPeer.java:553)
- Initializing leader election protocol...
[2011-04-05 21:35:34,887] INFO   109[QuorumPeer:7958910] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:655)
- New election. My id =  2, Proposed zxid = 0
[2011-04-05 21:35:34,889]DEBUG   111[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 1
[2011-04-05 21:35:34,896]DEBUG   118[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:360)
- Connected to server 1
[2011-04-05 21:35:34,939]DEBUG   161[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.<init>(QuorumCnxManager.java:573)
- Address of remote peer: 1
[2011-04-05 21:35:34,945]DEBUG   167[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 2
[2011-04-05 21:35:34,951]DEBUG   173[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 3
[2011-04-05 21:35:34,952] INFO   174[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 2
(n.sid), LOOKING (my state)
[2011-04-05 21:35:34,954]DEBUG   176[QuorumPeer:7958910] -
org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
- id: 2, proposed id: 2, zxid: 0, proposed zxid: 0
[2011-04-05 21:35:34,955]DEBUG   177[QuorumPeer:7958910] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
- Adding vote: From = 2, Proposed leader = 2, Porposed zxid = 0, Proposed
epoch = 1
[2011-04-05 21:35:34,956] WARN   178[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
- Cannot open channel to 3 at election address /127.0.0.1:3444
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
 at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
at java.net.Socket.connect(Socket.java:529)
 at
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:327)
 at
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:360)
at
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:333)
 at java.lang.Thread.run(Thread.java:680)
[2011-04-05 21:35:34,958]DEBUG   180[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 2
[2011-04-05 21:35:34,966] INFO   188[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 1 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
(n.sid), LOOKING (my state)
[2011-04-05 21:35:34,966]DEBUG   188[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 2
[2011-04-05 21:35:34,966] INFO   188[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
(n.sid), LOOKING (my state)
[2011-04-05 21:35:34,966]DEBUG   188[QuorumPeer:7958910] -
org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
- id: 1, proposed id: 2, zxid: 0, proposed zxid: 0
[2011-04-05 21:35:34,966]DEBUG   188[QuorumPeer:7958910] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
- Adding vote: From = 1, Proposed leader = 1, Porposed zxid = 0, Proposed
epoch = 1
[2011-04-05 21:35:34,966]DEBUG   188[QuorumPeer:7958910] -
org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
- id: 2, proposed id: 2, zxid: 0, proposed zxid: 0
[2011-04-05 21:35:34,967]DEBUG   189[QuorumPeer:7958910] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
- Adding vote: From = 1, Proposed leader = 2, Porposed zxid = 0, Proposed
epoch = 1
[2011-04-05 21:35:35,167]DEBUG   389[QuorumPeer:7958910] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:763)
- About to leave FLE instance: Leader= 2, Zxid = 0, My id = 2, My state =
LEADING
[2011-04-05 21:35:35,167] INFO   389[QuorumPeer:7958910] -
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:656) -
LEADING
[2011-04-05 21:35:53,523] INFO 18745[/127.0.0.1:2444] -
org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:497)
- Received connection request /127.0.0.1:49501
[2011-04-05 21:35:53,525]DEBUG 18747[/127.0.0.1:2444] -
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.<init>(QuorumCnxManager.java:573)
- Address of remote peer: 3
[2011-04-05 21:35:53,530]DEBUG 18752[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 2
[2011-04-05 21:35:53,530] INFO 18752[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 3
(n.sid), LEADING (my state)
[2011-04-05 21:35:53,530]DEBUG 18752[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:288)
- Sending new notification. My id =  2, Recipient = 3
[2011-04-05 21:35:53,531]DEBUG 18753[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:377)
- There is a connection already for server 3

Peer 3

mac-mini-de-andre-oriani:zab andre$ java -cp libs/log4j-1.2.16.jar:bin:conf
org.apache.zookeeper.server.quorum.QuorumPeerMain conf/zoo3.cfg
[2011-04-05 21:35:53,425] INFO     0[main] -
org.apache.zookeeper.server.quorum.QuorumPeerConfig.parse(QuorumPeerConfig.java:93)
- Reading configuration from: conf/zoo3.cfg
[2011-04-05 21:35:53,441] INFO    16[main] -
org.apache.zookeeper.server.quorum.QuorumPeerConfig.parseProperties(QuorumPeerConfig.java:314)
- Defaulting to majority quorums
[2011-04-05 21:35:53,469] INFO    44[main] -
org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:119)
- Starting quorum peer
[2011-04-05 21:35:53,474] INFO    49[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setTickTime(QuorumPeer.java:822)
- tickTime set to 2000
[2011-04-05 21:35:53,478] INFO    53[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setMinSessionTimeout(QuorumPeer.java:842)
- minSessionTimeout set to -1
[2011-04-05 21:35:53,478] INFO    53[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setMaxSessionTimeout(QuorumPeer.java:853)
- maxSessionTimeout set to -1
[2011-04-05 21:35:53,478] INFO    53[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setInitLimit(QuorumPeer.java:868)
- initLimit set to 5
[2011-04-05 21:35:53,490] INFO    65[Thread-2] -
org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:490)
- My election bind port: 0.0.0.0/0.0.0.0:3444
[2011-04-05 21:35:53,495]DEBUG    70[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:586) -
Starting quorum peer
[2011-04-05 21:35:53,495] INFO    70[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:622) -
LOOKING
[2011-04-05 21:35:53,495]DEBUG    70[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.QuorumPeer.makeLEStrategy(QuorumPeer.java:553)
- Initializing leader election protocol...
[2011-04-05 21:35:53,496] INFO    71[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:655)
- New election. My id =  3, Proposed zxid = 0
[2011-04-05 21:35:53,498]DEBUG    73[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 1
[2011-04-05 21:35:53,505]DEBUG    80[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:360)
- Connected to server 1
[2011-04-05 21:35:53,510]DEBUG    85[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.<init>(QuorumCnxManager.java:573)
- Address of remote peer: 1
[2011-04-05 21:35:53,514]DEBUG    89[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
- Opening channel to server 2
[2011-04-05 21:35:53,520]DEBUG    95[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 3
[2011-04-05 21:35:53,522] INFO    97[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 1 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
(n.sid), LOOKING (my state)
[2011-04-05 21:35:53,522]DEBUG    97[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 3
[2011-04-05 21:35:53,523] INFO    98[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
(n.sid), LOOKING (my state)
[2011-04-05 21:35:53,521]DEBUG    96[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:360)
- Connected to server 2
[2011-04-05 21:35:53,524]DEBUG    99[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
- id: 1, proposed id: 3, zxid: 0, proposed zxid: 0
[2011-04-05 21:35:53,524]DEBUG    99[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
- Adding vote: From = 1, Proposed leader = 1, Porposed zxid = 0, Proposed
epoch = 1
[2011-04-05 21:35:53,525]DEBUG   100[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
- id: 2, proposed id: 3, zxid: 0, proposed zxid: 0
[2011-04-05 21:35:53,525]DEBUG   100[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
- Adding vote: From = 1, Proposed leader = 2, Porposed zxid = 0, Proposed
epoch = 1
[2011-04-05 21:35:53,524]DEBUG    99[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 3
[2011-04-05 21:35:53,526] INFO   101[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), FOLLOWING (n.state),
1 (n.sid), LOOKING (my state)
[2011-04-05 21:35:53,524]DEBUG    99[WorkerSender(main)] -
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.<init>(QuorumCnxManager.java:573)
- Address of remote peer: 2
[2011-04-05 21:35:53,528]DEBUG   103[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 3
[2011-04-05 21:35:53,528] INFO   103[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 3
(n.sid), LOOKING (my state)
[2011-04-05 21:35:53,529]DEBUG   104[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
- id: 3, proposed id: 3, zxid: 0, proposed zxid: 0
[2011-04-05 21:35:53,529]DEBUG   104[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
- Adding vote: From = 3, Proposed leader = 3, Porposed zxid = 0, Proposed
epoch = 1
[2011-04-05 21:35:53,530]DEBUG   105[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 3
[2011-04-05 21:35:53,530] INFO   105[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 2
(n.sid), LOOKING (my state)
[2011-04-05 21:35:53,531]DEBUG   106[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
- id: 2, proposed id: 3, zxid: 0, proposed zxid: 0
[2011-04-05 21:35:53,531]DEBUG   106[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
- Adding vote: From = 2, Proposed leader = 2, Porposed zxid = 0, Proposed
epoch = 1
[2011-04-05 21:35:53,532]DEBUG   107[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
- Receive new notification message. My id = 3
[2011-04-05 21:35:53,532] INFO   107[WorkerReceiver(main)] -
org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
- Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LEADING (n.state), 2
(n.sid), LEADING (my state)
[2011-04-05 21:35:53,532] INFO   107[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:738)
- Oh gosh
[2011-04-05 21:35:53,533] INFO   108[QuorumPeer:9031454] -
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:656) -
LEADING
[2011-04-05 21:35:53,425] INFO     0[main] -
org.apache.zookeeper.server.quorum.QuorumPeerConfig.parse(QuorumPeerConfig.java:93)
- Reading configuration from: conf/zoo3.cfg
[2011-04-05 21:35:53,441] INFO    16[main] -
org.apache.zookeeper.server.quorum.QuorumPeerConfig.parseProperties(QuorumPeerConfig.java:314)
- Defaulting to majority quorums
[2011-04-05 21:35:53,469] INFO    44[main] -
org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:119)
- Starting quorum peer
[2011-04-05 21:35:53,474] INFO    49[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setTickTime(QuorumPeer.java:822)
- tickTime set to 2000
[2011-04-05 21:35:53,478] INFO    53[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setMinSessionTimeout(QuorumPeer.java:842)
- minSessionTimeout set to -1
[2011-04-05 21:35:53,478] INFO    53[main] -
org.apache.zookeeper.server.quorum.QuorumPeer.setMaxSessionTimeout(QuorumPeer.java:853)
- maxSessionTimeout set to -1
[2011-04-05 21:35:53,478] INFO    53[main]

Re: Understanding better the Fast Leader Election algorithm

Posted by Diogo Becker <di...@se.inf.tu-dresden.de>.
Hi André.

André Oriani <ra...@students.ic.unicamp.br> writes:

> Hi all,
>
> I am trying to extract a minimalistic version of the Zab protocol from
> Zookeeper (https://github.com/aoriani/zab, btw) . I doing that by bringing
> one class at time, starting from QuorumCnxManager.  I brought enough classes
> to run the Fast Leader Election . Some classes I had to stub. Consequently
>  the only zxid possible now is zero.
>
> I am not sure if I understood  the election algorithm .  I have three peers.
>  I start each one sequentially. So when 2  runs, it connects to 1. Both
> agree that 2 had won, because it has the greatest id so far and it has
> quorum. Thus 2 goes to leading state and 1 goes to following state. But then
> 2 becomes alive. It connects to 1 and 2. Having received votes from all
> peers including itself  and having the biggest id , it also goes to leading
> state.
>
> So we have 2 peers in the leading state. Is this wrong ? Or it is because I
> have not yet implement ( copied ) the NEW LEADER proposal? If so , how the
> election proceeds from this point ?

You have to implement the NEWLEADER proposal part.

The LEADING state means that the replica *thinks* it is the leader.
Actually the return value of lookForLeader is only a hint of who will be
the leader.  In the QuorumPeer, when a replica thinks it is the leader,
it creates a Leader object.  When a replica thinks another replica is
the leader, it creates a Follower object.  The leader (Leader.java)
accepts connections from followers.  It becomes a *real* leader after a
quorum of followers connected to it (it then sends the NEWLEADER message
to them), or it times out.  Upon timeout, the replica goes back to the
election algorithm.  So should happen with peer 3.

The algorithm implements a stable leader election. If there is a leader,
a late arriving replica with higher id (eg peer 3) doesn't demote the
actual leader.  It eventually receives notifications with LEADING and
FOLLOWING states only and then starts following the leader.

Ciao, Diogo

> I have added some logs bellow in case someone wants to take a look.
>
>
> Thanks and Regards,
> André
>
>
>
>
>
>
>
> Peer 1
>
> [2011-04-05 21:35:30,569] INFO     0[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerConfig.parse(QuorumPeerConfig.java:93)
> - Reading configuration from: conf/zoo1.cfg
> [2011-04-05 21:35:30,663] INFO    94[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerConfig.parseProperties(QuorumPeerConfig.java:314)
> - Defaulting to majority quorums
> [2011-04-05 21:35:30,684] INFO   115[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:119)
> - Starting quorum peer
> [2011-04-05 21:35:30,712] INFO   143[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setTickTime(QuorumPeer.java:822)
> - tickTime set to 2000
> [2011-04-05 21:35:30,730] INFO   161[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setMinSessionTimeout(QuorumPeer.java:842)
> - minSessionTimeout set to -1
> [2011-04-05 21:35:30,730] INFO   161[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setMaxSessionTimeout(QuorumPeer.java:853)
> - maxSessionTimeout set to -1
> [2011-04-05 21:35:30,730] INFO   161[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setInitLimit(QuorumPeer.java:868)
> - initLimit set to 5
> [2011-04-05 21:35:30,820] INFO   251[Thread-2] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:490)
> - My election bind port: 0.0.0.0/0.0.0.0:1444
> [2011-04-05 21:35:30,823]DEBUG   254[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:586) -
> Starting quorum peer
> [2011-04-05 21:35:30,823] INFO   254[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:622) -
> LOOKING
> [2011-04-05 21:35:30,824]DEBUG   255[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumPeer.makeLEStrategy(QuorumPeer.java:553)
> - Initializing leader election protocol...
> [2011-04-05 21:35:30,824] INFO   255[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:655)
> - New election. My id =  1, Proposed zxid = 0
> [2011-04-05 21:35:30,856]DEBUG   287[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 2
> [2011-04-05 21:35:30,857]DEBUG   288[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 1
> [2011-04-05 21:35:30,867] INFO   298[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 1 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
> (n.sid), LOOKING (my state)
> [2011-04-05 21:35:30,867]DEBUG   298[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
> - id: 1, proposed id: 1, zxid: 0, proposed zxid: 0
> [2011-04-05 21:35:30,870]DEBUG   301[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
> - Adding vote: From = 1, Proposed leader = 1, Porposed zxid = 0, Proposed
> epoch = 1
> [2011-04-05 21:35:30,932] WARN   363[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
> - Cannot open channel to 2 at election address /127.0.0.1:2444
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
>  at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
>  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
> at java.net.Socket.connect(Socket.java:529)
>  at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:327)
>  at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:360)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:333)
>  at java.lang.Thread.run(Thread.java:680)
> [2011-04-05 21:35:30,939]DEBUG   370[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 3
> [2011-04-05 21:35:30,939] WARN   370[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
> - Cannot open channel to 3 at election address /127.0.0.1:3444
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
>  at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
>  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
> at java.net.Socket.connect(Socket.java:529)
>  at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:327)
>  at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:360)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:333)
>  at java.lang.Thread.run(Thread.java:680)
> [2011-04-05 21:35:31,072]DEBUG   503[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
> - Queue size: 1
> [2011-04-05 21:35:31,073]DEBUG   504[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
> - Queue size: 1
> [2011-04-05 21:35:31,073]DEBUG   504[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 2
> [2011-04-05 21:35:31,074] WARN   505[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
> - Cannot open channel to 2 at election address /127.0.0.1:2444
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
>  at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
>  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
> at java.net.Socket.connect(Socket.java:529)
>  at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
>  at
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
> at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
> [2011-04-05 21:35:31,074]DEBUG   505[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 3
> [2011-04-05 21:35:31,075] WARN   506[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
> - Cannot open channel to 3 at election address /127.0.0.1:3444
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
>  at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
>  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
> at java.net.Socket.connect(Socket.java:529)
>  at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
>  at
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
> at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
> [2011-04-05 21:35:31,075] INFO   506[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:689)
> - Notification time out: 400
> [2011-04-05 21:35:31,476]DEBUG   907[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
> - Queue size: 1
> [2011-04-05 21:35:31,476]DEBUG   907[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
> - Queue size: 1
> [2011-04-05 21:35:31,477]DEBUG   908[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 2
> [2011-04-05 21:35:31,477] WARN   908[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
> - Cannot open channel to 2 at election address /127.0.0.1:2444
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
>  at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
>  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
> at java.net.Socket.connect(Socket.java:529)
>  at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
>  at
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
> at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
> [2011-04-05 21:35:31,478]DEBUG   909[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 3
> [2011-04-05 21:35:31,478] WARN   909[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
> - Cannot open channel to 3 at election address /127.0.0.1:3444
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
>  at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
>  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
> at java.net.Socket.connect(Socket.java:529)
>  at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
>  at
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
> at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
> [2011-04-05 21:35:31,479] INFO   910[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:689)
> - Notification time out: 800
> [2011-04-05 21:35:32,279]DEBUG  1710[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
> - Queue size: 1
> [2011-04-05 21:35:32,280]DEBUG  1711[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
> - Queue size: 1
> [2011-04-05 21:35:32,280]DEBUG  1711[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 2
> [2011-04-05 21:35:32,281] WARN  1712[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
> - Cannot open channel to 2 at election address /127.0.0.1:2444
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
>  at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
>  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
> at java.net.Socket.connect(Socket.java:529)
>  at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
>  at
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
> at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
> [2011-04-05 21:35:32,281]DEBUG  1712[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 3
> [2011-04-05 21:35:32,282] WARN  1713[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
> - Cannot open channel to 3 at election address /127.0.0.1:3444
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
>  at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
>  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
> at java.net.Socket.connect(Socket.java:529)
>  at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
>  at
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
> at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
> [2011-04-05 21:35:32,282] INFO  1713[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:689)
> - Notification time out: 1600
> [2011-04-05 21:35:33,883]DEBUG  3314[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
> - Queue size: 1
> [2011-04-05 21:35:33,883]DEBUG  3314[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.haveDelivered(QuorumCnxManager.java:402)
> - Queue size: 1
> [2011-04-05 21:35:33,883]DEBUG  3314[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 2
> [2011-04-05 21:35:33,884] WARN  3315[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
> - Cannot open channel to 2 at election address /127.0.0.1:2444
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
>  at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
>  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
> at java.net.Socket.connect(Socket.java:529)
>  at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
>  at
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
> at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
> [2011-04-05 21:35:33,884]DEBUG  3315[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 3
> [2011-04-05 21:35:33,885] WARN  3316[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
> - Cannot open channel to 3 at election address /127.0.0.1:3444
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
>  at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
>  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
> at java.net.Socket.connect(Socket.java:529)
>  at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:392)
>  at
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:680)
> at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:623)
> [2011-04-05 21:35:33,885] INFO  3316[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:689)
> - Notification time out: 3200
> [2011-04-05 21:35:34,897] INFO  4328[/127.0.0.1:1444] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:497)
> - Received connection request /127.0.0.1:49494
> [2011-04-05 21:35:34,953]DEBUG  4384[/127.0.0.1:1444] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.<init>(QuorumCnxManager.java:573)
> - Address of remote peer: 2
> [2011-04-05 21:35:34,958]DEBUG  4389[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 1
> [2011-04-05 21:35:34,958] INFO  4389[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 2
> (n.sid), LOOKING (my state)
> [2011-04-05 21:35:34,958]DEBUG  4389[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
> - id: 2, proposed id: 1, zxid: 0, proposed zxid: 0
> [2011-04-05 21:35:34,959] INFO  4390[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:713)
> - Updating proposal
> [2011-04-05 21:35:34,959]DEBUG  4390[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
> - Adding vote: From = 2, Proposed leader = 2, Porposed zxid = 0, Proposed
> epoch = 1
> [2011-04-05 21:35:34,960]DEBUG  4391[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:377)
> - There is a connection already for server 2
> [2011-04-05 21:35:34,960]DEBUG  4391[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 3
> [2011-04-05 21:35:34,960] WARN  4391[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
> - Cannot open channel to 3 at election address /127.0.0.1:3444
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
>  at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
>  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
> at java.net.Socket.connect(Socket.java:529)
>  at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:327)
>  at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:360)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:333)
>  at java.lang.Thread.run(Thread.java:680)
> [2011-04-05 21:35:34,961]DEBUG  4392[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 1
> [2011-04-05 21:35:34,962] INFO  4393[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
> (n.sid), LOOKING (my state)
> [2011-04-05 21:35:34,962]DEBUG  4393[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
> - id: 2, proposed id: 2, zxid: 0, proposed zxid: 0
> [2011-04-05 21:35:34,962]DEBUG  4393[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
> - Adding vote: From = 1, Proposed leader = 2, Porposed zxid = 0, Proposed
> epoch = 1
> [2011-04-05 21:35:35,162]DEBUG  4593[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.learningState(FastLeaderElection.java:597)
> - I'm a participant: 1
> [2011-04-05 21:35:35,163]DEBUG  4594[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:763)
> - About to leave FLE instance: Leader= 2, Zxid = 0, My id = 1, My state =
> FOLLOWING
> [2011-04-05 21:35:35,163] INFO  4594[QuorumPeer:24807938] -
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:644) -
> FOLLOWING
> [2011-04-05 21:35:53,510] INFO 22941[/127.0.0.1:1444] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:497)
> - Received connection request /127.0.0.1:49500
> [2011-04-05 21:35:53,511]DEBUG 22942[/127.0.0.1:1444] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.<init>(QuorumCnxManager.java:573)
> - Address of remote peer: 3
> [2011-04-05 21:35:53,514]DEBUG 22945[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 1
> [2011-04-05 21:35:53,514] INFO 22945[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 3
> (n.sid), FOLLOWING (my state)
> [2011-04-05 21:35:53,514]DEBUG 22945[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:288)
> - Sending new notification. My id =  1, Recipient = 3
> [2011-04-05 21:35:53,516]DEBUG 22947[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:377)
> - There is a connection already for server 3
> [2011-04-05 21:35:30,569] INFO     0[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerConfig.parse(QuorumPeerConfig.java:93)
> - Reading configuration from: conf/zoo1.cfg
> [2011-04-05 21:35:30,663] INFO    94[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerConfig.parseProperties(QuorumPeerConfig.java:314)
> - Defaulting to majority quorums
> [2011-04-05 21:35:30,684] INFO   115[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:119)
> - Starting quorum peer
> [2011-04-05 21:35:30,712] INFO   143[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setTickTime(QuorumPeer.java:822)
> - tickTime set to 2000
> [2011-04-05 21:35:30,730] INFO   161[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setMinSessionTimeout(QuorumPeer.java:842)
> - minSessionTimeout set to -1
> [2011-04-05 21:35:30,730] INFO   161[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setMaxSessionTimeout(QuorumPeer.java:853)
> - maxSessionTimeout set to -1
> [2011-04-05 21:35:30,730] INFO   161[main]
>
>
>
> Peer 2
>
> 2011-04-05 21:35:34,778] INFO     0[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerConfig.parse(QuorumPeerConfig.java:93)
> - Reading configuration from: conf/zoo2.cfg
> [2011-04-05 21:35:34,824] INFO    46[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerConfig.parseProperties(QuorumPeerConfig.java:314)
> - Defaulting to majority quorums
> [2011-04-05 21:35:34,848] INFO    70[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:119)
> - Starting quorum peer
> [2011-04-05 21:35:34,852] INFO    74[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setTickTime(QuorumPeer.java:822)
> - tickTime set to 2000
> [2011-04-05 21:35:34,857] INFO    79[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setMinSessionTimeout(QuorumPeer.java:842)
> - minSessionTimeout set to -1
> [2011-04-05 21:35:34,857] INFO    79[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setMaxSessionTimeout(QuorumPeer.java:853)
> - maxSessionTimeout set to -1
> [2011-04-05 21:35:34,857] INFO    79[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setInitLimit(QuorumPeer.java:868)
> - initLimit set to 5
> [2011-04-05 21:35:34,881] INFO   103[Thread-2] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:490)
> - My election bind port: 0.0.0.0/0.0.0.0:2444
> [2011-04-05 21:35:34,884]DEBUG   106[QuorumPeer:7958910] -
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:586) -
> Starting quorum peer
> [2011-04-05 21:35:34,884] INFO   106[QuorumPeer:7958910] -
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:622) -
> LOOKING
> [2011-04-05 21:35:34,885]DEBUG   107[QuorumPeer:7958910] -
> org.apache.zookeeper.server.quorum.QuorumPeer.makeLEStrategy(QuorumPeer.java:553)
> - Initializing leader election protocol...
> [2011-04-05 21:35:34,887] INFO   109[QuorumPeer:7958910] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:655)
> - New election. My id =  2, Proposed zxid = 0
> [2011-04-05 21:35:34,889]DEBUG   111[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 1
> [2011-04-05 21:35:34,896]DEBUG   118[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:360)
> - Connected to server 1
> [2011-04-05 21:35:34,939]DEBUG   161[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.<init>(QuorumCnxManager.java:573)
> - Address of remote peer: 1
> [2011-04-05 21:35:34,945]DEBUG   167[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 2
> [2011-04-05 21:35:34,951]DEBUG   173[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 3
> [2011-04-05 21:35:34,952] INFO   174[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 2
> (n.sid), LOOKING (my state)
> [2011-04-05 21:35:34,954]DEBUG   176[QuorumPeer:7958910] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
> - id: 2, proposed id: 2, zxid: 0, proposed zxid: 0
> [2011-04-05 21:35:34,955]DEBUG   177[QuorumPeer:7958910] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
> - Adding vote: From = 2, Proposed leader = 2, Porposed zxid = 0, Proposed
> epoch = 1
> [2011-04-05 21:35:34,956] WARN   178[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:372)
> - Cannot open channel to 3 at election address /127.0.0.1:3444
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351)
>  at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213)
> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200)
>  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)
> at java.net.Socket.connect(Socket.java:529)
>  at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:358)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:327)
>  at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:360)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:333)
>  at java.lang.Thread.run(Thread.java:680)
> [2011-04-05 21:35:34,958]DEBUG   180[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 2
> [2011-04-05 21:35:34,966] INFO   188[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 1 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
> (n.sid), LOOKING (my state)
> [2011-04-05 21:35:34,966]DEBUG   188[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 2
> [2011-04-05 21:35:34,966] INFO   188[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
> (n.sid), LOOKING (my state)
> [2011-04-05 21:35:34,966]DEBUG   188[QuorumPeer:7958910] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
> - id: 1, proposed id: 2, zxid: 0, proposed zxid: 0
> [2011-04-05 21:35:34,966]DEBUG   188[QuorumPeer:7958910] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
> - Adding vote: From = 1, Proposed leader = 1, Porposed zxid = 0, Proposed
> epoch = 1
> [2011-04-05 21:35:34,966]DEBUG   188[QuorumPeer:7958910] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
> - id: 2, proposed id: 2, zxid: 0, proposed zxid: 0
> [2011-04-05 21:35:34,967]DEBUG   189[QuorumPeer:7958910] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
> - Adding vote: From = 1, Proposed leader = 2, Porposed zxid = 0, Proposed
> epoch = 1
> [2011-04-05 21:35:35,167]DEBUG   389[QuorumPeer:7958910] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:763)
> - About to leave FLE instance: Leader= 2, Zxid = 0, My id = 2, My state =
> LEADING
> [2011-04-05 21:35:35,167] INFO   389[QuorumPeer:7958910] -
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:656) -
> LEADING
> [2011-04-05 21:35:53,523] INFO 18745[/127.0.0.1:2444] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:497)
> - Received connection request /127.0.0.1:49501
> [2011-04-05 21:35:53,525]DEBUG 18747[/127.0.0.1:2444] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.<init>(QuorumCnxManager.java:573)
> - Address of remote peer: 3
> [2011-04-05 21:35:53,530]DEBUG 18752[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 2
> [2011-04-05 21:35:53,530] INFO 18752[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 3
> (n.sid), LEADING (my state)
> [2011-04-05 21:35:53,530]DEBUG 18752[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:288)
> - Sending new notification. My id =  2, Recipient = 3
> [2011-04-05 21:35:53,531]DEBUG 18753[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:377)
> - There is a connection already for server 3
>
> Peer 3
>
> mac-mini-de-andre-oriani:zab andre$ java -cp libs/log4j-1.2.16.jar:bin:conf
> org.apache.zookeeper.server.quorum.QuorumPeerMain conf/zoo3.cfg
> [2011-04-05 21:35:53,425] INFO     0[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerConfig.parse(QuorumPeerConfig.java:93)
> - Reading configuration from: conf/zoo3.cfg
> [2011-04-05 21:35:53,441] INFO    16[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerConfig.parseProperties(QuorumPeerConfig.java:314)
> - Defaulting to majority quorums
> [2011-04-05 21:35:53,469] INFO    44[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:119)
> - Starting quorum peer
> [2011-04-05 21:35:53,474] INFO    49[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setTickTime(QuorumPeer.java:822)
> - tickTime set to 2000
> [2011-04-05 21:35:53,478] INFO    53[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setMinSessionTimeout(QuorumPeer.java:842)
> - minSessionTimeout set to -1
> [2011-04-05 21:35:53,478] INFO    53[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setMaxSessionTimeout(QuorumPeer.java:853)
> - maxSessionTimeout set to -1
> [2011-04-05 21:35:53,478] INFO    53[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setInitLimit(QuorumPeer.java:868)
> - initLimit set to 5
> [2011-04-05 21:35:53,490] INFO    65[Thread-2] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:490)
> - My election bind port: 0.0.0.0/0.0.0.0:3444
> [2011-04-05 21:35:53,495]DEBUG    70[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:586) -
> Starting quorum peer
> [2011-04-05 21:35:53,495] INFO    70[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:622) -
> LOOKING
> [2011-04-05 21:35:53,495]DEBUG    70[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.QuorumPeer.makeLEStrategy(QuorumPeer.java:553)
> - Initializing leader election protocol...
> [2011-04-05 21:35:53,496] INFO    71[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:655)
> - New election. My id =  3, Proposed zxid = 0
> [2011-04-05 21:35:53,498]DEBUG    73[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 1
> [2011-04-05 21:35:53,505]DEBUG    80[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:360)
> - Connected to server 1
> [2011-04-05 21:35:53,510]DEBUG    85[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.<init>(QuorumCnxManager.java:573)
> - Address of remote peer: 1
> [2011-04-05 21:35:53,514]DEBUG    89[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:354)
> - Opening channel to server 2
> [2011-04-05 21:35:53,520]DEBUG    95[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 3
> [2011-04-05 21:35:53,522] INFO    97[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 1 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
> (n.sid), LOOKING (my state)
> [2011-04-05 21:35:53,522]DEBUG    97[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 3
> [2011-04-05 21:35:53,523] INFO    98[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
> (n.sid), LOOKING (my state)
> [2011-04-05 21:35:53,521]DEBUG    96[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:360)
> - Connected to server 2
> [2011-04-05 21:35:53,524]DEBUG    99[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
> - id: 1, proposed id: 3, zxid: 0, proposed zxid: 0
> [2011-04-05 21:35:53,524]DEBUG    99[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
> - Adding vote: From = 1, Proposed leader = 1, Porposed zxid = 0, Proposed
> epoch = 1
> [2011-04-05 21:35:53,525]DEBUG   100[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
> - id: 2, proposed id: 3, zxid: 0, proposed zxid: 0
> [2011-04-05 21:35:53,525]DEBUG   100[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
> - Adding vote: From = 1, Proposed leader = 2, Porposed zxid = 0, Proposed
> epoch = 1
> [2011-04-05 21:35:53,524]DEBUG    99[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 3
> [2011-04-05 21:35:53,526] INFO   101[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), FOLLOWING (n.state),
> 1 (n.sid), LOOKING (my state)
> [2011-04-05 21:35:53,524]DEBUG    99[WorkerSender(main)] -
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.<init>(QuorumCnxManager.java:573)
> - Address of remote peer: 2
> [2011-04-05 21:35:53,528]DEBUG   103[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 3
> [2011-04-05 21:35:53,528] INFO   103[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 3
> (n.sid), LOOKING (my state)
> [2011-04-05 21:35:53,529]DEBUG   104[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
> - id: 3, proposed id: 3, zxid: 0, proposed zxid: 0
> [2011-04-05 21:35:53,529]DEBUG   104[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
> - Adding vote: From = 3, Proposed leader = 3, Porposed zxid = 0, Proposed
> epoch = 1
> [2011-04-05 21:35:53,530]DEBUG   105[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 3
> [2011-04-05 21:35:53,530] INFO   105[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 2
> (n.sid), LOOKING (my state)
> [2011-04-05 21:35:53,531]DEBUG   106[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.totalOrderPredicate(FastLeaderElection.java:510)
> - id: 2, proposed id: 3, zxid: 0, proposed zxid: 0
> [2011-04-05 21:35:53,531]DEBUG   106[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:719)
> - Adding vote: From = 2, Proposed leader = 2, Porposed zxid = 0, Proposed
> epoch = 1
> [2011-04-05 21:35:53,532]DEBUG   107[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:214)
> - Receive new notification message. My id = 3
> [2011-04-05 21:35:53,532] INFO   107[WorkerReceiver(main)] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.printNotification(FastLeaderElection.java:496)
> - Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), LEADING (n.state), 2
> (n.sid), LEADING (my state)
> [2011-04-05 21:35:53,532] INFO   107[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:738)
> - Oh gosh
> [2011-04-05 21:35:53,533] INFO   108[QuorumPeer:9031454] -
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:656) -
> LEADING
> [2011-04-05 21:35:53,425] INFO     0[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerConfig.parse(QuorumPeerConfig.java:93)
> - Reading configuration from: conf/zoo3.cfg
> [2011-04-05 21:35:53,441] INFO    16[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerConfig.parseProperties(QuorumPeerConfig.java:314)
> - Defaulting to majority quorums
> [2011-04-05 21:35:53,469] INFO    44[main] -
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:119)
> - Starting quorum peer
> [2011-04-05 21:35:53,474] INFO    49[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setTickTime(QuorumPeer.java:822)
> - tickTime set to 2000
> [2011-04-05 21:35:53,478] INFO    53[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setMinSessionTimeout(QuorumPeer.java:842)
> - minSessionTimeout set to -1
> [2011-04-05 21:35:53,478] INFO    53[main] -
> org.apache.zookeeper.server.quorum.QuorumPeer.setMaxSessionTimeout(QuorumPeer.java:853)
> - maxSessionTimeout set to -1
> [2011-04-05 21:35:53,478] INFO    53[main]