zookeeper-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Benjamin Jaton <benjamin.ja...@gmail.com>
Subject Re: Help looking at ZK logs
Date Thu, 12 May 2016 22:47:26 GMT
bump

On Wed, May 4, 2016 at 2:55 PM, Benjamin Jaton <benjamin.jaton@gmail.com>
wrote:

> Hello,
>
> I have a 2 nodes ZK ensemble, the first node shows:
>
> WARN
> [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@93]
> - Exception when following the leader
> java.net.SocketTimeoutException: Read timed out
>         at java.net.SocketInputStream.socketRead0(Native Method)
> ~[?:1.8.0_91]
>         at
> java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
> ~[?:1.8.0_91]
>         at java.net.SocketInputStream.read(SocketInputStream.java:170)
> ~[?:1.8.0_91]
>         at java.net.SocketInputStream.read(SocketInputStream.java:141)
> ~[?:1.8.0_91]
>         at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
> ~[?:1.8.0_91]
>         at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
> ~[?:1.8.0_91]
>         at java.io.DataInputStream.readInt(DataInputStream.java:387)
> ~[?:1.8.0_91]
>         at
> org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
> ~[zookeeper-3.5.0-alpha.jar:3.5.2-alpha-SNAPSHOT-1702518]
>         at
> org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
> ~[zookeeper-3.5.0-alpha.jar:?]
>         at
> org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
> ~[zookeeper-3.5.0-alpha.jar:3.5.2-alpha-SNAPSHOT-1702518]
>         at
> org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:155)
> ~[zookeeper-3.5.0-alpha.jar:?]
>         at
> org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:89)
> [zookeeper-3.5.0-alpha.jar:?]
>         at
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1064)
> [zookeeper-3.5.0-alpha.jar:?]
>
> [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@198]
> - shutdown called
> java.lang.Exception: shutdown Follower
>         at
> org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
> [zookeeper-3.5.0-alpha.jar:?]
>         at
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1068)
> [zookeeper-3.5.0-alpha.jar:?]
>
>
> and proceeds to go into read-ony mode.
> The second node shows:
>
>
> 2016-05-04T13:15:27,819 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@606] - Closed socket connection for
> client /127.0.1.1:45412 which had sessionid 0x2000092b4fa0052
> 2016-05-04T13:15:27,932 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45416
> 2016-05-04T13:15:27,940 [myid:] - INFO
> [NIOWorkerThread-2:ZooKeeperServer@969] - Client attempting to establish
> new session at /127.0.1.1:45416
> 2016-05-04T13:15:27,961 [myid:] - INFO
> [CommitProcWorkThread-1:ZooKeeperServer@678] - Established session
> 0x2000092b4fa0053 with negotiated timeout 60000 for client /
> 127.0.1.1:45416
> 2016-05-04T13:15:27,961 [myid:] - INFO
> [NIOWorkerThread-2:ZooKeeperServer@1006] - got auth packet /
> 127.0.1.1:45416
> 2016-05-04T13:15:27,962 [myid:] - INFO
> [NIOWorkerThread-2:ZooKeeperServer@1024] - auth success /127.0.1.1:45416
> 2016-05-04T13:15:27,962 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@1006] - got auth packet /
> 127.0.1.1:45416
> 2016-05-04T13:15:27,962 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@1024] - auth success /127.0.1.1:45416
> 2016-05-04T13:15:28,054 [myid:] - INFO  [ProcessThread(sid:2
> cport:-1)::PrepRequestProcessor@649] - Processed session termination for
> sessionid: 0x10005f496940051
> 2016-05-04T13:15:40,659 [myid:] - INFO  [SessionTracker:ZooKeeperServer@384]
> - Expiring session 0x10005f496940050, timeout of 5000ms exceeded
> 2016-05-04T13:15:40,659 [myid:] - INFO
> [SessionTracker:QuorumZooKeeperServer@132] - Submitting global
> closeSession request for session 0x10005f496940050
> 2016-05-04T13:15:40,659 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45427
> 2016-05-04T13:15:40,659 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45429
> 2016-05-04T13:15:40,660 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45431
> 2016-05-04T13:15:40,660 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /10.11.12.4:51958
> 2016-05-04T13:15:40,660 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /10.11.12.4:51959
> 2016-05-04T13:15:40,660 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45433
> 2016-05-04T13:15:40,663 [myid:] - INFO  [ProcessThread(sid:2
> cport:-1)::PrepRequestProcessor@649] - Processed session termination for
> sessionid: 0x10005f496940050
> 2016-05-04T13:15:41,190 [myid:] - INFO
> [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2
> (message format version), 1 (n.leader), 0x70000056d (n.zxid), 0x2
> (n.round), LOOKING (n.state), 1 (n.sid), 0x7 (n.peerEPoch), LEADING (my
> state)10000041c (n.config version)
> 2016-05-04T13:15:41,193 [myid:] - INFO
> [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2
> (message format version), 1 (n.leader), 0x70000056d (n.zxid), 0x2
> (n.round), LOOKING (n.state), 1 (n.sid), 0x7 (n.peerEPoch), LEADING (my
> state)10000041c (n.config version)
> 2016-05-04T13:15:41,193 [myid:] - INFO
> [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2
> (message format version), 1 (n.leader), 0x70000056d (n.zxid), 0x2
> (n.round), LOOKING (n.state), 1 (n.sid), 0x7 (n.peerEPoch), LEADING (my
> state)10000041c (n.config version)
> 2016-05-04T13:15:41,193 [myid:] - INFO
> [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2
> (message format version), 1 (n.leader), 0x70000056d (n.zxid), 0x2
> (n.round), LOOKING (n.state), 1 (n.sid), 0x7 (n.peerEPoch), LEADING (my
> state)10000041c (n.config version)
> 2016-05-04T13:15:41,194 [myid:] - INFO
> [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2
> (message format version), 1 (n.leader), 0x70000056d (n.zxid), 0x2
> (n.round), LOOKING (n.state), 1 (n.sid), 0x7 (n.peerEPoch), LEADING (my
> state)10000041c (n.config version)
> 2016-05-04T13:15:41,259 [myid:] - INFO
> [NIOWorkerThread-2:ZooKeeperServer@974] - Client attempting to renew
> session 0x10005f496940002 at /10.11.12.4:51958
> 2016-05-04T13:15:41,260 [myid:] - INFO
> [NIOWorkerThread-2:ZooKeeperServer@678] - Established session
> 0x10005f496940002 with negotiated timeout 60000 for client /
> 10.11.12.4:51958
> 2016-05-04T13:15:41,260 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@974] - Client attempting to renew
> session 0x10005f496940005 at /127.0.1.1:45433
> 2016-05-04T13:15:41,260 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@678] - Established session
> 0x10005f496940005 with negotiated timeout 60000 for client /
> 127.0.1.1:45433
> 2016-05-04T13:15:41,261 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@969] - Client attempting to establish
> new session at /127.0.1.1:45427
> 2016-05-04T13:15:41,261 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@969] - Client attempting to establish
> new session at /127.0.1.1:45429
> 2016-05-04T13:15:41,261 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@974] - Client attempting to renew
> session 0x10005f496940000 at /10.11.12.4:51959
> 2016-05-04T13:15:41,261 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@678] - Established session
> 0x10005f496940000 with negotiated timeout 60000 for client /
> 10.11.12.4:51959
> 2016-05-04T13:15:41,261 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@969] - Client attempting to establish
> new session at /127.0.1.1:45431
> 2016-05-04T13:15:41,275 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@1006] - got auth packet /
> 10.11.12.4:51958
> 2016-05-04T13:15:41,275 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@1024] - auth success /10.11.12.4:51958
> 2016-05-04T13:15:41,275 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@1006] - got auth packet /
> 127.0.1.1:45433
> 2016-05-04T13:15:41,275 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@1024] - auth success /127.0.1.1:45433
> 2016-05-04T13:15:41,275 [myid:] - INFO
> [NIOWorkerThread-2:ZooKeeperServer@1006] - got auth packet /
> 10.11.12.4:51959
> 2016-05-04T13:15:41,276 [myid:] - INFO
> [NIOWorkerThread-2:ZooKeeperServer@1024] - auth success /10.11.12.4:51959
> 2016-05-04T13:15:40,661 [myid:] - ERROR [LearnerHandler-/10.11.12.4:39206
> :LearnerHandler@620] - Unexpected exception causing shutdown while sock
> still open
> java.io.EOFException
>     at java.io.DataInputStream.readInt(DataInputStream.java:392)
> ~[?:1.8.0_91]
>     at
> org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
> ~[zookeeper-3.5.0-alpha.jar:3.5.2-alpha-SNAPSHOT-1702518]
>     at
> org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
> ~[zookeeper-3.5.0-alpha.jar:?]
>     at
> org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
> ~[zookeeper-3.5.0-alpha.jar:3.5.2-alpha-SNAPSHOT-1702518]
>     at
> org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:514)
> [zookeeper-3.5.0-alpha.jar:?]
> 2016-05-04T13:15:41,267 [myid:] - WARN  [Sender-/10.11.12.4:39206
> :LearnerHandler@241] - Unexpected exception at LearnerHandler
> Socket[addr=/10.11.12.4,port=39206,localport=2888]
> tickOfNextAckDeadline:1331 synced?:true queuedPacketLength:3
> java.net.SocketException: Broken pipe
>     at java.net.SocketOutputStream.socketWrite0(Native Method)
> ~[?:1.8.0_91]
>     at
> java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109)
> ~[?:1.8.0_91]
>     at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
> ~[?:1.8.0_91]
>     at
> java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
> ~[?:1.8.0_91]
>     at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
> ~[?:1.8.0_91]
>     at
> org.apache.zookeeper.server.quorum.LearnerHandler.sendPackets(LearnerHandler.java:221)
> [zookeeper-3.5.0-alpha.jar:?]
>     at
> org.apache.zookeeper.server.quorum.LearnerHandler.access$200(LearnerHandler.java:58)
> [zookeeper-3.5.0-alpha.jar:?]
>     at
> org.apache.zookeeper.server.quorum.LearnerHandler$1.run(LearnerHandler.java:653)
> [zookeeper-3.5.0-alpha.jar:?]
> 2016-05-04T13:15:42,066 [myid:] - WARN  [LearnerHandler-/10.11.12.4:39206
> :LearnerHandler@635] - ******* GOODBYE /10.11.12.4:39206 ********
> 2016-05-04T13:15:42,394 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45438
> 2016-05-04T13:15:42,395 [myid:] - INFO
> [NIOWorkerThread-1:ZooKeeperServer@969] - Client attempting to establish
> new session at /127.0.1.1:45438
> 2016-05-04T13:15:42,984 [myid:] - WARN  [SyncThread:2:FileTxnLog@335] -
> fsync-ing the write ahead log in SyncThread:2 took 1721ms which will
> adversely effect operation latency. See the ZooKeeper troubleshooting guide
> 2016-05-04T13:15:43,043 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Leader@613]
> - Shutting down
> 2016-05-04T13:15:43,071 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Leader@619]
> - Shutdown called
> java.lang.Exception: shutdown Leader! reason: Not sufficient followers
> synced, only synced with sids: [ [2] ]
>     at org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:619)
> [zookeeper-3.5.0-alpha.jar:?]
>     at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:590)
> [zookeeper-3.5.0-alpha.jar:?]
>     at
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1077)
> [zookeeper-3.5.0-alpha.jar:?]
> 2016-05-04T13:15:43,161 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
> - Closed socket connection for client /127.0.1.1:45431 which had
> sessionid 0x2000092b4fa0056
> 2016-05-04T13:15:43,161 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader,name3=Connections,name4=10.11.12.4,name5=0x2000092b4fa0000]
> 2016-05-04T13:15:43,161 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
> - Closed socket connection for client /10.11.12.4:59834 which had
> sessionid 0x2000092b4fa0000
> 2016-05-04T13:15:43,162 [myid:] - INFO
> [LearnerCnxAcceptor-0.0.0.0/0.0.0.0:2888:Leader$LearnerCnxAcceptor@373] -
> exception while shutting down acceptor: java.net.SocketException: Socket
> closed
> 2016-05-04T13:15:43,162 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
> - Closed socket connection for client /127.0.1.1:45438 which had
> sessionid 0x2000092b4fa0057
> 2016-05-04T13:15:43,171 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader,name3=Connections,name4=127.0.1.1,name5=0x2000092b4fa0002]
> 2016-05-04T13:15:43,171 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
> - Closed socket connection for client /127.0.1.1:35055 which had
> sessionid 0x2000092b4fa0002
> 2016-05-04T13:15:43,172 [myid:] - INFO
> [main-SendThread(ubuntu2:2181):ClientCnxn$SendThread@1253] - Unable to
> read additional data from server sessionid 0x2000092b4fa0002, likely server
> has closed socket, closing socket connection and attempting reconnect
> 2016-05-04T13:15:43,172 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
> - Closed socket connection for client /127.0.1.1:45427 which had
> sessionid 0x2000092b4fa0054
> 2016-05-04T13:15:43,172 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@498]
> - shutting down
> 2016-05-04T13:15:43,172 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):SessionTrackerImpl@232]
> - Shutting down
> 2016-05-04T13:15:43,172 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):LeaderRequestProcessor@77]
> - Shutting down
> 2016-05-04T13:15:43,172 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):PrepRequestProcessor@967]
> - Shutting down
> 2016-05-04T13:15:43,173 [myid:] - INFO  [ProcessThread(sid:2
> cport:-1)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop!
> 2016-05-04T13:15:43,173 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ProposalRequestProcessor@88]
> - Shutting down
> 2016-05-04T13:15:43,174 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):CommitProcessor@358]
> - Shutting down
> 2016-05-04T13:15:43,174 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Leader$ToBeAppliedRequestProcessor@914]
> - Shutting down
> 2016-05-04T13:15:43,175 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):FinalRequestProcessor@492]
> - shutdown of request processor complete
> 2016-05-04T13:15:43,175 [myid:] - INFO
> [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):SyncRequestProcessor@191]
> - Shutting down
> 2016-05-04T13:15:43,210 [myid:] - INFO
> [CommitProcessor:2:CommitProcessor@193] - CommitProcessor exited loop!
> 2016-05-04T13:15:43,440 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45441
> 2016-05-04T13:15:43,441 [myid:] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@485] - Processing isro command from /
> 127.0.1.1:45441
> 2016-05-04T13:15:43,458 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /10.11.12.4:51963
> 2016-05-04T13:15:43,458 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@485] - Processing isro command from /
> 10.11.12.4:51963
> 2016-05-04T13:15:43,558 [myid:] - INFO
> [main-EventThread:ConnectionStateManager@228] - State change: SUSPENDED
> 2016-05-04T13:15:43,607 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /10.11.12.4:51965
> 2016-05-04T13:15:43,731 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45444
> 2016-05-04T13:15:43,796 [myid:] - INFO
> [Curator-ConnectionStateManager-0:ZooManagerConnectionStateListener@104]
> - Curator connection state change: SUSPENDED (session: 144115818177363970)
> 2016-05-04T13:15:43,797 [myid:] - WARN
> [Curator-ConnectionStateManager-0:ZooManagerConnectionStateListener@48] -
> Connection suspended (session: 144115818177363970)
> 2016-05-04T13:15:43,797 [myid:] - INFO
> [Curator-ConnectionStateManager-0:ZooManagerConnectionStateListener@139]
> - Starting session lost thread for session 144115818177363970
> 2016-05-04T13:15:43,825 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /10.11.12.4:51967
> 2016-05-04T13:15:43,946 [myid:] - INFO
> [main-SendThread(w-rli09-ben:2181):ClientCnxn$SendThread@1138] - Opening
> socket connection to server w-rli09-ben/10.11.12.4:2181. Will not attempt
> to authenticate using SASL (unknown error)
> 2016-05-04T13:15:43,947 [myid:] - INFO
> [main-SendThread(w-rli09-ben:2181):ClientCnxn$SendThread@980] - Socket
> connection established, initiating session, client: /10.11.1.2:56315,
> server: w-rli09-ben/10.11.12.4:2181
> 2016-05-04T13:15:43,949 [myid:] - INFO
> [main-SendThread(w-rli09-ben:2181):ClientCnxn$SendThread@1400] - Session
> establishment complete on server w-rli09-ben/10.11.12.4:2181, sessionid =
> 0x2000092b4fa0002, negotiated timeout = 60000 (READ-ONLY mode)
> 2016-05-04T13:15:43,949 [myid:] - INFO
> [main-EventThread:ConnectionStateManager@228] - State change: READ_ONLY
> 2016-05-04T13:15:43,949 [myid:] - INFO
> [Curator-ConnectionStateManager-0:ZooManagerConnectionStateListener@104]
> - Curator connection state change: READ_ONLY (session: 144115818177363970)
> 2016-05-04T13:15:43,949 [myid:] - INFO
> [Curator-ConnectionStateManager-0:ZooManagerConnectionStateListener@206]
> - VDS-ZK connection state changed: READ_ONLY
> 2016-05-04T13:15:44,007 [myid:] - WARN
> [Curator-ConnectionStateManager-0:ZooManager@300] - ZooManager connection
> state changed: READ_ONLY
> 2016-05-04T13:15:44,007 [myid:] - INFO
> [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop!
> 2016-05-04T13:15:44,029 [myid:] - INFO
> [main-SendThread(w-rli09-ben:2181):ClientCnxn$SendThread@1297] - Checking
> server ubuntu2/127.0.1.1:2181 for being r/w. Timeout 200
> 2016-05-04T13:15:44,030 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45447
> 2016-05-04T13:15:44,170 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@606] - Closed socket connection for
> client /10.11.12.4:51963 (no session established for client)
> 2016-05-04T13:15:44,171 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@485] - Processing isro command from /
> 10.11.12.4:51965
> 2016-05-04T13:15:44,171 [myid:] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@606] - Closed socket connection for
> client /127.0.1.1:45441 (no session established for client)
> 2016-05-04T13:15:44,171 [myid:] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@485] - Processing isro command from /
> 127.0.1.1:45444
> 2016-05-04T13:15:44,171 [myid:] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@606] - Closed socket connection for
> client /127.0.1.1:45444 (no session established for client)
> 2016-05-04T13:15:44,171 [myid:] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@485] - Processing isro command from /
> 10.11.12.4:51967
> 2016-05-04T13:15:44,174 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@606] - Closed socket connection for
> client /10.11.12.4:51965 (no session established for client)
> 2016-05-04T13:15:44,175 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@485] - Processing isro command from /
> 127.0.1.1:45447
> 2016-05-04T13:15:44,175 [myid:] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@606] - Closed socket connection for
> client /10.11.12.4:51967 (no session established for client)
> 2016-05-04T13:15:44,177 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@606] - Closed socket connection for
> client /127.0.1.1:45447 (no session established for client)
> 2016-05-04T13:15:44,190 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /10.11.12.4:51970
> 2016-05-04T13:15:44,191 [myid:] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@485] - Processing isro command from /
> 10.11.12.4:51970
> 2016-05-04T13:15:44,191 [myid:] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@606] - Closed socket connection for
> client /10.11.12.4:51970 (no session established for client)
> 2016-05-04T13:15:44,210 [myid:] - INFO
> [main-SendThread(w-rli09-ben:2181):ClientCnxn$SendThread@1297] - Checking
> server w-rli09-ben/10.11.12.4:2181 for being r/w. Timeout 400
> 2016-05-04T13:15:44,470 [myid:] - INFO
> [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2
> (message format version), 1 (n.leader), 0x70000056d (n.zxid), 0x2
> (n.round), LOOKING (n.state), 1 (n.sid), 0x7 (n.peerEPoch), LEADING (my
> state)10000041c (n.config version)
> 2016-05-04T13:15:44,578 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /10.11.12.4:51972
> 2016-05-04T13:15:44,579 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@485] - Processing isro command from /
> 10.11.12.4:51972
> 2016-05-04T13:15:44,579 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@606] - Closed socket connection for
> client /10.11.12.4:51972 (no session established for client)
> 2016-05-04T13:15:44,609 [myid:] - INFO
> [main-SendThread(w-rli09-ben:2181):ClientCnxn$SendThread@1297] - Checking
> server ubuntu2/127.0.1.1:2181 for being r/w. Timeout 800
> 2016-05-04T13:15:44,610 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45454
> 2016-05-04T13:15:44,610 [myid:] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@485] - Processing isro command from /
> 127.0.1.1:45454
> 2016-05-04T13:15:44,611 [myid:] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@606] - Closed socket connection for
> client /127.0.1.1:45454 (no session established for client)
> 2016-05-04T13:15:44,780 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45455
> 2016-05-04T13:15:44,780 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@485] - Processing isro command from /
> 127.0.1.1:45455
> 2016-05-04T13:15:44,781 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@606] - Closed socket connection for
> client /127.0.1.1:45455 (no session established for client)
> 2016-05-04T13:15:44,844 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45456
> 2016-05-04T13:15:44,846 [myid:] - WARN
> [NIOWorkerThread-2:NIOServerCnxn@369] - Exception causing close of
> session 0x0: ZooKeeperServer not running
> 2016-05-04T13:15:44,846 [myid:] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@606] - Closed socket connection for
> client /127.0.1.1:45456 (no session established for client)
> 2016-05-04T13:15:45,314 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /10.11.12.4:51975
> 2016-05-04T13:15:45,315 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@485] - Processing isro command from /
> 10.11.12.4:51975
> 2016-05-04T13:15:45,315 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@606] - Closed socket connection for
> client /10.11.12.4:51975 (no session established for client)
> 2016-05-04T13:15:45,376 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45457
> 2016-05-04T13:15:45,376 [myid:] - WARN
> [NIOWorkerThread-2:NIOServerCnxn@369] - Exception causing close of
> session 0x0: ZooKeeperServer not running
> 2016-05-04T13:15:45,376 [myid:] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@606] - Closed socket connection for
> client /127.0.1.1:45457 (no session established for client)
> 2016-05-04T13:15:45,410 [myid:] - INFO
> [main-SendThread(w-rli09-ben:2181):ClientCnxn$SendThread@1297] - Checking
> server w-rli09-ben/10.11.12.4:2181 for being r/w. Timeout 1600
> 2016-05-04T13:15:46,423 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45462
> 2016-05-04T13:15:46,425 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@485] - Processing isro command from /
> 127.0.1.1:45462
> 2016-05-04T13:15:46,508 [myid:] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@606] - Closed socket connection for
> client /127.0.1.1:45462 (no session established for client)
> 2016-05-04T13:15:46,643 [myid:] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
> :NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from
> /127.0.1.1:45463
> 2016-05-04T13:15:46,643 [myid:] - WARN
> [NIOWorkerThread-2:NIOServerCnxn@369] - Exception causing close of
> session 0x0: ZooKeeperServer not running
>
>
>
> So I have several question:
> Is the second node supposed to retry recreating an ensemble at some point?
> Or was there a critical error?
> What does it mean to repeat "ZooKeeperServer not running" when the JVM is
> still running?
>
> Thanks a lot,
> Ben
>
>
>
>
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message