Return-Path: X-Original-To: apmail-zookeeper-user-archive@www.apache.org Delivered-To: apmail-zookeeper-user-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id B033A18520 for ; Mon, 10 Aug 2015 17:51:06 +0000 (UTC) Received: (qmail 32472 invoked by uid 500); 10 Aug 2015 17:51:06 -0000 Delivered-To: apmail-zookeeper-user-archive@zookeeper.apache.org Received: (qmail 32421 invoked by uid 500); 10 Aug 2015 17:51:05 -0000 Mailing-List: contact user-help@zookeeper.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: user@zookeeper.apache.org Delivered-To: mailing list user@zookeeper.apache.org Received: (qmail 32409 invoked by uid 99); 10 Aug 2015 17:51:05 -0000 Received: from Unknown (HELO spamd4-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 10 Aug 2015 17:51:05 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd4-us-west.apache.org (ASF Mail Server at spamd4-us-west.apache.org) with ESMTP id 0DF43C130A for ; Mon, 10 Aug 2015 17:51:05 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd4-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 4.902 X-Spam-Level: **** X-Spam-Status: No, score=4.902 tagged_above=-999 required=6.31 tests=[DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, HTML_MESSAGE=3, KAM_BADIPHTTP=2, NORMAL_HTTP_TO_IP=0.001, SPF_PASS=-0.001, URIBL_BLOCKED=0.001, WEIRD_PORT=0.001] autolearn=disabled Authentication-Results: spamd4-us-west.apache.org (amavisd-new); dkim=pass (2048-bit key) header.d=gmail.com Received: from mx1-eu-west.apache.org ([10.40.0.8]) by localhost (spamd4-us-west.apache.org [10.40.0.11]) (amavisd-new, port 10024) with ESMTP id 1CWrB8PZNnKU for ; Mon, 10 Aug 2015 17:50:48 +0000 (UTC) Received: from mail-ig0-f181.google.com (mail-ig0-f181.google.com [209.85.213.181]) by mx1-eu-west.apache.org (ASF Mail Server at mx1-eu-west.apache.org) with ESMTPS id 4D17520B86 for ; Mon, 10 Aug 2015 17:50:47 +0000 (UTC) Received: by igfj19 with SMTP id j19so54999930igf.1 for ; Mon, 10 Aug 2015 10:50:46 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:date:message-id:subject:from:to:content-type; bh=lds2UDQyZJ675Bepi+qY+h2O/NG9ZBwcEYsPyIomet0=; b=GHgx6s1xYQGyWzKqifUG6Z4AGUEn9MsClethOrz30/hyXGqwkveQVfAZwF1sjTuKwf +/WaIafcWgadhb1w6WJLYprFXM1RepNQuKXTPcPTPsymltgA9mkcz07Sc1OCLRVyFqyG y0cki2L3CdtwYQGBlE/Hx3MoDk8Ll9/Xznp3p0tc85UnyU75F13pvUIDp465FL14GcOK KlJ9zxwJ7o8lg/iIH/8q+054MvswCXiTqsp8Bh4QwpPa/rdRH3pWGIN3i1q6ROXsU7Kf oWkjx44j4mp7pmG57mopnjO6h3gt5cs/uMgAHqiVGkfBLZonOGqrrl77lP7dC+omkP4d 1Gwg== MIME-Version: 1.0 X-Received: by 10.50.25.226 with SMTP id f2mr12510379igg.87.1439229046164; Mon, 10 Aug 2015 10:50:46 -0700 (PDT) Received: by 10.79.33.13 with HTTP; Mon, 10 Aug 2015 10:50:46 -0700 (PDT) Date: Mon, 10 Aug 2015 23:20:46 +0530 Message-ID: Subject: Zookeeper clients unable to get lock From: Prabhjot Bharaj To: user@zookeeper.apache.org Content-Type: multipart/alternative; boundary=047d7bd75b400c157b051cf8a024 --047d7bd75b400c157b051cf8a024 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Hello Friends, I have seen a strange behaviour in zookeeper. I'm starting zookeeper server on 3 nodes (within less than 5 seconds). Also, after 10 seconds of starting the server, I'm starting clients on 3 machines. All the 3 clients try to acquire lock. But, none of them is able to get the lock. My theory is:- 1. Nodes are not clustered together properly, when clients try to get lock. But, 10 seconds is too much of a time for the nodes to get clustered together. Not sure of the reason So, I'm pasting entire info log from 3 zookeeper servers here. Appreciate your help in finding the root of this. Thanks, Prabcs Info logs on 198.18.85.48 . 85 and 106 are at the bottom of the page =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 2015-08-10 13:44:15,917 - INFO [main:QuorumPeerConfig@103] - Reading configuration from: /a/dna_zookeeper/conf/zoo.cfg 2015-08-10 13:44:15,922 - INFO [main:QuorumPeerConfig@340] - Defaulting to majority quorums 2015-08-10 13:44:15,927 - INFO [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3 2015-08-10 13:44:15,927 - INFO [main:DatadirCleanupManager@79] - autopurge.purgeInterval set to 0 2015-08-10 13:44:15,928 - INFO [main:DatadirCleanupManager@101] - Purge task is not scheduled. 2015-08-10 13:44:15,940 - INFO [main:QuorumPeerMain@127] - Starting quorum peer 2015-08-10 13:44:15,953 - INFO [main:NIOServerCnxnFactory@94] - binding to port 0.0.0.0/0.0.0.0:2181 2015-08-10 13:44:15,973 - INFO [main:QuorumPeer@959] - tickTime set to 200= 0 2015-08-10 13:44:15,973 - INFO [main:QuorumPeer@979] - minSessionTimeout set to -1 2015-08-10 13:44:15,974 - INFO [main:QuorumPeer@990] - maxSessionTimeout set to -1 2015-08-10 13:44:15,974 - INFO [main:QuorumPeer@1005] - initLimit set to 1= 0 2015-08-10 13:44:15,989 - INFO [main:FileSnap@83] - Reading snapshot /zookeeper_data/version-2/snapshot.1500000019 2015-08-10 13:44:16,019 - INFO [Thread-1:QuorumCnxManager$Listener@504] - My election bind port: /198.18.85.48:3888 2015-08-10 13:44:16,029 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:QuorumPeer@714] - LOOKING 2015-08-10 13:44:16,031 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:FastLeaderElection@815] - New election. My id =3D 2, proposed zxid=3D0x1700000018 2015-08-10 13:44:16,034 - WARN [WorkerSender[myid=3D2]:QuorumCnxManager@38= 2] - Cannot open channel to 1 at election address /198.18.85.106:3888 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339= ) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.j= ava:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxMan= ager.java:368) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager= .java:341) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSende= r.process(FastLeaderElection.java:449) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSende= r.run(FastLeaderElection.java:430) at java.lang.Thread.run(Thread.java:745) 2015-08-10 13:44:16,039 - WARN [WorkerSender[myid=3D2]:QuorumCnxManager@38= 2] - Cannot open channel to 3 at election address /198.18.85.85:3888 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339= ) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.j= ava:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxMan= ager.java:368) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager= .java:341) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSende= r.process(FastLeaderElection.java:449) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSende= r.run(FastLeaderElection.java:430) at java.lang.Thread.run(Thread.java:745) 2015-08-10 13:44:16,039 - INFO [WorkerReceiver[myid=3D2]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 2 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x17 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:16,242 - WARN [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:QuorumCnxManager@382] - Cannot open channel to 1 at election address /198.18.85.106:3888 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339= ) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.j= ava:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxMan= ager.java:368) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxMan= ager.java:402) at org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLea= derElection.java:840) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:762) 2015-08-10 13:44:16,243 - WARN [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:QuorumCnxManager@382] - Cannot open channel to 3 at election address /198.18.85.85:3888 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339= ) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.j= ava:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxMan= ager.java:368) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxMan= ager.java:402) at org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLea= derElection.java:840) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:762) 2015-08-10 13:44:16,243 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:FastLeaderElection@849] - Notification time out: 400 2015-08-10 13:44:16,644 - WARN [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:QuorumCnxManager@382] - Cannot open channel to 1 at election address /198.18.85.106:3888 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339= ) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.j= ava:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxMan= ager.java:368) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxMan= ager.java:402) at org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLea= derElection.java:840) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:762) 2015-08-10 13:44:16,645 - WARN [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:QuorumCnxManager@382] - Cannot open channel to 3 at election address /198.18.85.85:3888 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339= ) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.j= ava:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxMan= ager.java:368) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxMan= ager.java:402) at org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLea= derElection.java:840) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:762) 2015-08-10 13:44:16,645 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:FastLeaderElection@849] - Notification time out: 800 2015-08-10 13:44:17,446 - WARN [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:QuorumCnxManager@382] - Cannot open channel to 1 at election address /198.18.85.106:3888 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339= ) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.j= ava:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxMan= ager.java:368) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxMan= ager.java:402) at org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLea= derElection.java:840) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:762) 2015-08-10 13:44:17,447 - WARN [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:QuorumCnxManager@382] - Cannot open channel to 3 at election address /198.18.85.85:3888 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339= ) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.j= ava:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxMan= ager.java:368) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxMan= ager.java:402) at org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLea= derElection.java:840) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:762) 2015-08-10 13:44:17,447 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:FastLeaderElection@849] - Notification time out: 1600 2015-08-10 13:44:17,665 - INFO [/198.18.85.48:3888 :QuorumCnxManager$Listener@511] - Received connection request / 198.18.85.85:45728 2015-08-10 13:44:17,669 - INFO [WorkerReceiver[myid=3D2]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x17 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:17,669 - WARN [WorkerSender[myid=3D2]:QuorumCnxManager@38= 2] - Cannot open channel to 1 at election address /198.18.85.106:3888 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339= ) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.j= ava:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxMan= ager.java:368) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager= .java:341) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSende= r.process(FastLeaderElection.java:449) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSende= r.run(FastLeaderElection.java:430) at java.lang.Thread.run(Thread.java:745) 2015-08-10 13:44:17,670 - INFO [WorkerReceiver[myid=3D2]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x17 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:17,871 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:QuorumPeer@784] - FOLLOWING 2015-08-10 13:44:17,876 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Learner@86] - TCP NoDelay set to= : true 2015-08-10 13:44:17,883 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:zookeeper.version=3D3.4.6-1569965, built on 02/20/2014 09:09 GM= T 2015-08-10 13:44:17,884 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:host.name=3Da198-18-85-48. 2015-08-10 13:44:17,884 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.version=3D1.7.0_75 2015-08-10 13:44:17,884 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.vendor=3DOracle Corporation 2015-08-10 13:44:17,884 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.home=3D/usr/local/java/jdk1.7.0/jre 2015-08-10 13:44:17,884 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.class.path=3D/a/dna_zookeeper/lib/slf4j-log4j12-1.6.1.jar:= /a/dna_zookeeper/lib/slf4j-api-1.6.1.jar:/a/dna_zookeeper/lib/netty-3.7.0.F= inal.jar:/a/dna_zookeeper/lib/log4j-1.2.16.jar:/a/dna_zookeeper/lib/jline-0= .9.94.jar:/a/dna_zookeeper/bin/zookeeper-3.4.6.jar:/a/dna_zookeeper/conf::/= usr/local/lib:/usr/local/lib:/usr/local/lib 2015-08-10 13:44:17,884 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.library.path=3D:/usr/local/lib:/usr/local/lib:/usr/local/l= ib:/usr/java/packages/lib/i386:/lib:/usr/lib 2015-08-10 13:44:17,884 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.io.tmpdir=3D/tmp 2015-08-10 13:44:17,884 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.compiler=3D 2015-08-10 13:44:17,884 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.name=3DLinux 2015-08-10 13:44:17,884 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.arch=3Di386 2015-08-10 13:44:17,885 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.version=3D3.14.35-3.14.1.1-amd64-15536989 2015-08-10 13:44:17,885 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.name=3Droot 2015-08-10 13:44:17,885 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.home=3D/root 2015-08-10 13:44:17,885 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.dir=3D/usr/local/tmp 2015-08-10 13:44:17,886 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:ZooKeeperServer@162] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /zookeeper_data/version-2 snapdir /zookeeper_data/version-2 2015-08-10 13:44:17,887 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Follower@63] - FOLLOWING - LEADE= R ELECTION TOOK - 1856 2015-08-10 13:44:17,890 - WARN [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Learner@233] - Unexpected exception, tries=3D0, connecting to /198.18.85.85:2888 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339= ) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.j= ava:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.Learner.connectToLeader(Learner.java:225= ) at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:71) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:786) 2015-08-10 13:44:18,905 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Learner@323] - Getting a diff fr= om the leader 0x1700000018 2015-08-10 13:44:18,910 - INFO [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:FileTxnSnapLog@240] - Snapshotting: 0x1700000018 to /zookeeper_data/version-2/snapshot.1700000018 2015-08-10 13:44:19,203 - INFO [/198.18.85.48:3888 :QuorumCnxManager$Listener@511] - Received connection request / 198.18.85.106:60242 2015-08-10 13:44:19,210 - INFO [WorkerReceiver[myid=3D2]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 1 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x17 (n.peerEpoch) FOLLOWING (my state) 2015-08-10 13:44:19,211 - INFO [WorkerReceiver[myid=3D2]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x17 (n.peerEpoch) FOLLOWING (my state) 2015-08-10 13:44:25,924 - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /198.18.85.48:33057 2015-08-10 13:44:25,930 - WARN [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@822] - Connection request from old client /198.18.85.48:33057; will be dropped if server is in r-o mode 2015-08-10 13:44:25,931 - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@868] - Client attempting to establish new session at /198.18.85.48:33057 2015-08-10 13:44:25,932 - WARN [QuorumPeer[myid=3D2]/0:0:0:0:0:0:0:0:2181:Follower@118] - Got zxid 0x1800000001 expected 0x1 2015-08-10 13:44:25,933 - INFO [SyncThread:2:FileTxnLog@199] - Creating new log file: log.1800000001 2015-08-10 13:44:25,938 - INFO [CommitProcessor:2:ZooKeeperServer@617] - Established session 0x24f17dacadc0000 with negotiated timeout 30000 for client /198.18.85.48:33057 2015-08-10 13:44:25,966 - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /198.18.85.48:33058 2015-08-10 13:44:25,967 - WARN [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@822] - Connection request from old client /198.18.85.48:33058; will be dropped if server is in r-o mode 2015-08-10 13:44:25,967 - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@868] - Client attempting to establish new session at /198.18.85.48:33058 2015-08-10 13:44:25,968 - INFO [CommitProcessor:2:ZooKeeperServer@617] - Established session 0x24f17dacadc0001 with negotiated timeout 10000 for client /198.18.85.48:33058 2015-08-10 13:44:29,078 - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /198.18.85.106:56296 2015-08-10 13:44:29,079 - WARN [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@822] - Connection request from old client /198.18.85.106:56296; will be dropped if server is in r-o mode 2015-08-10 13:44:29,079 - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@868] - Client attempting to establish new session at /198.18.85.106:56296 2015-08-10 13:44:29,080 - INFO [CommitProcessor:2:ZooKeeperServer@617] - Established session 0x24f17dacadc0002 with negotiated timeout 10000 for client /198.18.85.106:56296 =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D Info logs on 198.18.85.85 . 106 is at the bottom of the page =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 2015-08-10 13:44:17,509 - INFO [main:QuorumPeerConfig@103] - Reading configuration from: /a/dna_zookeeper/conf/zoo.cfg 2015-08-10 13:44:17,515 - INFO [main:QuorumPeerConfig@340] - Defaulting to majority quorums 2015-08-10 13:44:17,521 - INFO [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3 2015-08-10 13:44:17,521 - INFO [main:DatadirCleanupManager@79] - autopurge.purgeInterval set to 0 2015-08-10 13:44:17,522 - INFO [main:DatadirCleanupManager@101] - Purge task is not scheduled. 2015-08-10 13:44:17,539 - INFO [main:QuorumPeerMain@127] - Starting quorum peer 2015-08-10 13:44:17,556 - INFO [main:NIOServerCnxnFactory@94] - binding to port 0.0.0.0/0.0.0.0:2181 2015-08-10 13:44:17,582 - INFO [main:QuorumPeer@959] - tickTime set to 200= 0 2015-08-10 13:44:17,582 - INFO [main:QuorumPeer@979] - minSessionTimeout set to -1 2015-08-10 13:44:17,582 - INFO [main:QuorumPeer@990] - maxSessionTimeout set to -1 2015-08-10 13:44:17,582 - INFO [main:QuorumPeer@1005] - initLimit set to 1= 0 2015-08-10 13:44:17,603 - INFO [main:FileSnap@83] - Reading snapshot /zookeeper_data/version-2/snapshot.1600000035 2015-08-10 13:44:17,640 - INFO [Thread-1:QuorumCnxManager$Listener@504] - My election bind port: /198.18.85.85:3888 2015-08-10 13:44:17,654 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:QuorumPeer@714] - LOOKING 2015-08-10 13:44:17,655 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:FastLeaderElection@815] - New election. My id =3D 3, proposed zxid=3D0x1700000018 2015-08-10 13:44:17,660 - WARN [WorkerSender[myid=3D3]:QuorumCnxManager@38= 2] - Cannot open channel to 1 at election address /198.18.85.106:3888 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339= ) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.j= ava:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxMan= ager.java:368) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager= .java:341) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSende= r.process(FastLeaderElection.java:449) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSende= r.run(FastLeaderElection.java:430) at java.lang.Thread.run(Thread.java:745) 2015-08-10 13:44:17,671 - INFO [WorkerReceiver[myid=3D3]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x17 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:17,672 - INFO [WorkerReceiver[myid=3D3]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 2 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x17 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:17,672 - INFO [WorkerReceiver[myid=3D3]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x17 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:17,873 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:QuorumPeer@796] - LEADING 2015-08-10 13:44:17,878 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Leader@60] - TCP NoDelay set to: true 2015-08-10 13:44:17,889 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:zookeeper.version=3D3.4.6-1569965, built on 02/20/2014 09:09 GM= T 2015-08-10 13:44:17,889 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:host.name=3Da198-18-85-85. 2015-08-10 13:44:17,889 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.version=3D1.7.0_75 2015-08-10 13:44:17,889 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.vendor=3DOracle Corporation 2015-08-10 13:44:17,889 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.home=3D/usr/local/java/jdk1.7.0/jre 2015-08-10 13:44:17,889 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.class.path=3D/a/dna_zookeeper/lib/slf4j-log4j12-1.6.1.jar:= /a/dna_zookeeper/lib/slf4j-api-1.6.1.jar:/a/dna_zookeeper/lib/netty-3.7.0.F= inal.jar:/a/dna_zookeeper/lib/log4j-1.2.16.jar:/a/dna_zookeeper/lib/jline-0= .9.94.jar:/a/dna_zookeeper/bin/zookeeper-3.4.6.jar:/a/dna_zookeeper/conf::/= usr/local/lib:/usr/local/lib:/usr/local/lib 2015-08-10 13:44:17,890 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.library.path=3D:/usr/local/lib:/usr/local/lib:/usr/local/l= ib:/usr/java/packages/lib/i386:/lib:/usr/lib 2015-08-10 13:44:17,890 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.io.tmpdir=3D/tmp 2015-08-10 13:44:17,890 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.compiler=3D 2015-08-10 13:44:17,890 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.name=3DLinux 2015-08-10 13:44:17,890 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.arch=3Di386 2015-08-10 13:44:17,890 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.version=3D3.14.35-3.14.1.1-amd64-15536989 2015-08-10 13:44:17,890 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.name=3Droot 2015-08-10 13:44:17,891 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.home=3D/root 2015-08-10 13:44:17,891 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.dir=3D/usr/local/tmp 2015-08-10 13:44:17,893 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:ZooKeeperServer@162] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /zookeeper_data/version-2 snapdir /zookeeper_data/version-2 2015-08-10 13:44:17,894 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Leader@358] - LEADING - LEADER ELECTION TOOK - 239 2015-08-10 13:44:18,901 - INFO [LearnerHandler-/198.18.85.48:34143 :LearnerHandler@330] - Follower sid: 2 : info : org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@1b84411 2015-08-10 13:44:18,906 - INFO [LearnerHandler-/198.18.85.48:34143 :LearnerHandler@385] - Synchronizing with Follower sid: 2 maxCommittedLog=3D0x1700000018 minCommittedLog=3D0x1700000001 peerLastZxid=3D0x1700000018 2015-08-10 13:44:18,906 - INFO [LearnerHandler-/198.18.85.48:34143 :LearnerHandler@462] - Sending DIFF 2015-08-10 13:44:18,913 - INFO [LearnerHandler-/198.18.85.48:34143 :LearnerHandler@522] - Received NEWLEADER-ACK message from 2 2015-08-10 13:44:18,916 - INFO [QuorumPeer[myid=3D3]/0:0:0:0:0:0:0:0:2181:Leader@943] - Have quorum of supporters, sids: [ 2,3 ]; starting up and setting last processed zxid: 0x1800000000 2015-08-10 13:44:19,208 - INFO [/198.18.85.85:3888 :QuorumCnxManager$Listener@511] - Received connection request / 198.18.85.106:48469 2015-08-10 13:44:19,212 - INFO [WorkerReceiver[myid=3D3]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 1 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x17 (n.peerEpoch) LEADING (my state) 2015-08-10 13:44:19,213 - INFO [WorkerReceiver[myid=3D3]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x17 (n.peerEpoch) LEADING (my state) 2015-08-10 13:44:19,241 - INFO [LearnerHandler-/198.18.85.106:36014 :LearnerHandler@330] - Follower sid: 1 : info : org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@8e5360 2015-08-10 13:44:19,243 - INFO [LearnerHandler-/198.18.85.106:36014 :LearnerHandler@385] - Synchronizing with Follower sid: 1 maxCommittedLog=3D0x1700000018 minCommittedLog=3D0x1700000001 peerLastZxid=3D0x1700000018 2015-08-10 13:44:19,243 - INFO [LearnerHandler-/198.18.85.106:36014 :LearnerHandler@462] - Sending DIFF 2015-08-10 13:44:19,253 - INFO [LearnerHandler-/198.18.85.106:36014 :LearnerHandler@522] - Received NEWLEADER-ACK message from 1 2015-08-10 13:44:25,934 - INFO [SyncThread:3:FileTxnLog@199] - Creating new log file: log.1800000001 2015-08-10 13:44:27,565 - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /198.18.85.85:57552 2015-08-10 13:44:27,572 - WARN [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@822] - Connection request from old client /198.18.85.85:57552; will be dropped if server is in r-o mode 2015-08-10 13:44:27,573 - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@868] - Client attempting to establish new session at /198.18.85.85:57552 2015-08-10 13:44:27,579 - INFO [CommitProcessor:3:ZooKeeperServer@617] - Established session 0x34f17dacae60000 with negotiated timeout 10000 for client /198.18.85.85:57552 2015-08-10 13:44:30,000 - INFO [SessionTracker:ZooKeeperServer@347] - Expiring session 0x34f17d862b90001, timeout of 10000ms exceeded 2015-08-10 13:44:30,000 - INFO [SessionTracker:ZooKeeperServer@347] - Expiring session 0x14f17d85f780000, timeout of 10000ms exceeded 2015-08-10 13:44:30,000 - INFO [SessionTracker:ZooKeeperServer@347] - Expiring session 0x24f17d85f800001, timeout of 10000ms exceeded 2015-08-10 13:44:30,000 - INFO [SessionTracker:ZooKeeperServer@347] - Expiring session 0x34f17d862b90003, timeout of 10000ms exceeded 2015-08-10 13:44:30,001 - INFO [ProcessThread(sid:3 cport:-1)::PrepRequestProcessor@494] - Processed session termination for sessionid: 0x34f17d862b90001 2015-08-10 13:44:30,001 - INFO [ProcessThread(sid:3 cport:-1)::PrepRequestProcessor@494] - Processed session termination for sessionid: 0x14f17d85f780000 2015-08-10 13:44:30,001 - INFO [ProcessThread(sid:3 cport:-1)::PrepRequestProcessor@494] - Processed session termination for sessionid: 0x24f17d85f800001 2015-08-10 13:44:30,001 - INFO [ProcessThread(sid:3 cport:-1)::PrepRequestProcessor@494] - Processed session termination for sessionid: 0x34f17d862b90003 2015-08-10 13:44:50,000 - INFO [SessionTracker:ZooKeeperServer@347] - Expiring session 0x34f17d862b90002, timeout of 30000ms exceeded 2015-08-10 13:44:50,001 - INFO [SessionTracker:ZooKeeperServer@347] - Expiring session 0x24f17d85f800000, timeout of 30000ms exceeded 2015-08-10 13:44:50,001 - INFO [SessionTracker:ZooKeeperServer@347] - Expiring session 0x34f17d862b90000, timeout of 30000ms exceeded 2015-08-10 13:44:50,001 - INFO [ProcessThread(sid:3 cport:-1)::PrepRequestProcessor@494] - Processed session termination for sessionid: 0x34f17d862b90002 2015-08-10 13:44:50,001 - INFO [ProcessThread(sid:3 cport:-1)::PrepRequestProcessor@494] - Processed session termination for sessionid: 0x24f17d85f800000 2015-08-10 13:44:50,002 - INFO [ProcessThread(sid:3 cport:-1)::PrepRequestProcessor@494] - Processed session termination for sessionid: 0x34f17d862b90000 =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D Info logs on 198.18.85.106 =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 2015-08-10 13:44:19,051 - INFO [main:QuorumPeerConfig@103] - Reading configuration from: /a/dna_zookeeper/conf/zoo.cfg 2015-08-10 13:44:19,057 - INFO [main:QuorumPeerConfig@340] - Defaulting to majority quorums 2015-08-10 13:44:19,064 - INFO [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3 2015-08-10 13:44:19,064 - INFO [main:DatadirCleanupManager@79] - autopurge.purgeInterval set to 0 2015-08-10 13:44:19,065 - INFO [main:DatadirCleanupManager@101] - Purge task is not scheduled. 2015-08-10 13:44:19,082 - INFO [main:QuorumPeerMain@127] - Starting quorum peer 2015-08-10 13:44:19,099 - INFO [main:NIOServerCnxnFactory@94] - binding to port 0.0.0.0/0.0.0.0:2181 2015-08-10 13:44:19,127 - INFO [main:QuorumPeer@959] - tickTime set to 200= 0 2015-08-10 13:44:19,127 - INFO [main:QuorumPeer@979] - minSessionTimeout set to -1 2015-08-10 13:44:19,128 - INFO [main:QuorumPeer@990] - maxSessionTimeout set to -1 2015-08-10 13:44:19,128 - INFO [main:QuorumPeer@1005] - initLimit set to 1= 0 2015-08-10 13:44:19,148 - INFO [main:FileSnap@83] - Reading snapshot /zookeeper_data/version-2/snapshot.1600000035 2015-08-10 13:44:19,184 - INFO [Thread-1:QuorumCnxManager$Listener@504] - My election bind port: /198.18.85.106:3888 2015-08-10 13:44:19,198 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:QuorumPeer@714] - LOOKING 2015-08-10 13:44:19,200 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:FastLeaderElection@815] - New election. My id =3D 1, proposed zxid=3D0x1700000018 2015-08-10 13:44:19,202 - INFO [WorkerReceiver[myid=3D1]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 1 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x17 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:19,207 - INFO [WorkerSender[myid=3D1]:QuorumCnxManager@19= 3] - Have smaller server identifier, so dropping the connection: (2, 1) 2015-08-10 13:44:19,208 - INFO [/198.18.85.106:3888 :QuorumCnxManager$Listener@511] - Received connection request / 198.18.85.48:40751 2015-08-10 13:44:19,208 - INFO [WorkerSender[myid=3D1]:QuorumCnxManager@19= 3] - Have smaller server identifier, so dropping the connection: (3, 1) 2015-08-10 13:44:19,211 - INFO [/198.18.85.106:3888 :QuorumCnxManager$Listener@511] - Received connection request / 198.18.85.85:58481 2015-08-10 13:44:19,212 - INFO [WorkerReceiver[myid=3D1]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x17 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:19,212 - INFO [WorkerReceiver[myid=3D1]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x17 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:19,213 - INFO [WorkerReceiver[myid=3D1]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x17 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:19,213 - INFO [WorkerReceiver[myid=3D1]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LEADING (n.state), 3 (n.sid), 0x18 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:19,213 - INFO [WorkerReceiver[myid=3D1]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), LEADING (n.state), 3 (n.sid), 0x18 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:19,214 - INFO [WorkerReceiver[myid=3D1]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), FOLLOWING (n.state), 2 (n.sid), 0x18 (n.peerEpoch) LOOKING (my state) 2015-08-10 13:44:19,214 - INFO [WorkerReceiver[myid=3D1]:FastLeaderElection@597] - Notification: 1 (messag= e format version), 3 (n.leader), 0x1700000018 (n.zxid), 0x1 (n.round), FOLLOWING (n.state), 2 (n.sid), 0x18 (n.peerEpoch) FOLLOWING (my state) 2015-08-10 13:44:19,214 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:QuorumPeer@784] - FOLLOWING 2015-08-10 13:44:19,221 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Learner@86] - TCP NoDelay set to= : true 2015-08-10 13:44:19,231 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:zookeeper.version=3D3.4.6-1569965, built on 02/20/2014 09:09 GM= T 2015-08-10 13:44:19,231 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:host.name=3Da198-18-85-106. 2015-08-10 13:44:19,231 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.version=3D1.7.0_75 2015-08-10 13:44:19,231 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.vendor=3DOracle Corporation 2015-08-10 13:44:19,232 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.home=3D/usr/local/java/jdk1.7.0/jre 2015-08-10 13:44:19,232 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.class.path=3D/a/dna_zookeeper/lib/slf4j-log4j12-1.6.1.jar:= /a/dna_zookeeper/lib/slf4j-api-1.6.1.jar:/a/dna_zookeeper/lib/netty-3.7.0.F= inal.jar:/a/dna_zookeeper/lib/log4j-1.2.16.jar:/a/dna_zookeeper/lib/jline-0= .9.94.jar:/a/dna_zookeeper/bin/zookeeper-3.4.6.jar:/a/dna_zookeeper/conf::/= usr/local/lib:/usr/local/lib:/usr/local/lib 2015-08-10 13:44:19,232 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.library.path=3D:/usr/local/lib:/usr/local/lib:/usr/local/l= ib:/usr/java/packages/lib/i386:/lib:/usr/lib 2015-08-10 13:44:19,232 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.io.tmpdir=3D/tmp 2015-08-10 13:44:19,232 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.compiler=3D 2015-08-10 13:44:19,232 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.name=3DLinux 2015-08-10 13:44:19,232 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.arch=3Di386 2015-08-10 13:44:19,233 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.version=3D3.14.35-3.14.1.1-amd64-15536989 2015-08-10 13:44:19,233 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.name=3Droot 2015-08-10 13:44:19,233 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.home=3D/root 2015-08-10 13:44:19,233 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.dir=3D/usr/local/tmp 2015-08-10 13:44:19,235 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:ZooKeeperServer@162] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /zookeeper_data/version-2 snapdir /zookeeper_data/version-2 2015-08-10 13:44:19,236 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Follower@63] - FOLLOWING - LEADE= R ELECTION TOOK - 37 2015-08-10 13:44:19,244 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Learner@323] - Getting a diff fr= om the leader 0x1700000018 2015-08-10 13:44:19,250 - INFO [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:FileTxnSnapLog@240] - Snapshotting: 0x1700000018 to /zookeeper_data/version-2/snapshot.1700000018 2015-08-10 13:44:25,934 - WARN [QuorumPeer[myid=3D1]/0:0:0:0:0:0:0:0:2181:Follower@118] - Got zxid 0x1800000001 expected 0x1 2015-08-10 13:44:25,935 - INFO [SyncThread:1:FileTxnLog@199] - Creating new log file: log.1800000001 2015-08-10 13:44:27,516 - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /198.18.85.85:33490 2015-08-10 13:44:27,524 - WARN [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@822] - Connection request from old client /198.18.85.85:33490; will be dropped if server is in r-o mode 2015-08-10 13:44:27,525 - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@868] - Client attempting to establish new session at /198.18.85.85:33490 2015-08-10 13:44:27,531 - INFO [CommitProcessor:1:ZooKeeperServer@617] - Established session 0x14f17dacc2f0000 with negotiated timeout 30000 for client /198.18.85.85:33490 2015-08-10 13:44:29,059 - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /198.18.85.106:34327 2015-08-10 13:44:29,060 - WARN [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@822] - Connection request from old client /198.18.85.106:34327; will be dropped if server is in r-o mode 2015-08-10 13:44:29,060 - INFO [NIOServerCxn.Factory: 0.0.0.0/0.0.0.0:2181:ZooKeeperServer@868] - Client attempting to establish new session at /198.18.85.106:34327 2015-08-10 13:44:29,062 - INFO [CommitProcessor:1:ZooKeeperServer@617] - Established session 0x14f17dacc2f0001 with negotiated timeout 30000 for client /198.18.85.106:34327 --047d7bd75b400c157b051cf8a024--