2018-08-07 06:55:32,531 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x40089b0086b0000 type:delete cxid:0x15df70b zxid:0x3006c7271 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904f.europe.intranet Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904f.europe.intranet 2018-08-07 06:55:52,586 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x40089b0086b0000 type:delete cxid:0x15df7d0 zxid:0x3006c72c0 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904e.europe.intranet Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904e.europe.intranet 2018-08-07 11:04:23,591 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x40089b0086b0000 type:delete cxid:0x160323e zxid:0x3006d596f txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904j.europe.intranet Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904j.europe.intranet 2018-08-07 11:04:35,630 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x40089b0086b0000 type:delete cxid:0x16032c0 zxid:0x3006d59a4 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904j.europe.intranet Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904j.europe.intranet 2018-08-07 12:57:38,354 [myid:] - INFO [main:QuorumPeerConfig@130] - Reading configuration from: /opt/zookeeper/bin/../conf/zoo.cfg 2018-08-07 12:57:38,360 [myid:] - INFO [main:QuorumPeerConfig@366] - clientPort is not set 2018-08-07 12:57:38,360 [myid:] - INFO [main:QuorumPeerConfig@380] - secureClientPort is not set 2018-08-07 12:57:38,381 [myid:5] - INFO [main:ManagedUtil@46] - Log4j found with jmx enabled. 2018-08-07 12:57:38,393 [myid:5] - INFO [main:QuorumPeerMain@141] - Starting quorum peer 2018-08-07 12:57:38,438 [myid:5] - INFO [main:Log@186] - Logging initialized @750ms 2018-08-07 12:57:38,484 [myid:5] - WARN [main:ContextHandler@1339] - o.e.j.s.ServletContextHandler@224edc67{/,null,null} contextPath ends with /* 2018-08-07 12:57:38,484 [myid:5] - WARN [main:ContextHandler@1350] - Empty contextPath 2018-08-07 12:57:38,493 [myid:5] - INFO [main:QuorumPeer@1430] - Local sessions disabled 2018-08-07 12:57:38,494 [myid:5] - INFO [main:QuorumPeer@1441] - Local session upgrading disabled 2018-08-07 12:57:38,494 [myid:5] - INFO [main:QuorumPeer@1408] - tickTime set to 1000 2018-08-07 12:57:38,494 [myid:5] - INFO [main:QuorumPeer@1452] - minSessionTimeout set to 2000 2018-08-07 12:57:38,494 [myid:5] - INFO [main:QuorumPeer@1463] - maxSessionTimeout set to 20000 2018-08-07 12:57:38,494 [myid:5] - INFO [main:QuorumPeer@1478] - initLimit set to 10 2018-08-07 12:57:38,503 [myid:5] - INFO [main:ZKDatabase@117] - zookeeper.snapshotSizeFactor = 0.33 2018-08-07 12:57:38,504 [myid:5] - INFO [main:QuorumPeer@2036] - QuorumPeer communication is not secured! 2018-08-07 12:57:38,504 [myid:5] - INFO [main:QuorumPeer@2065] - quorum.cnxn.threads.size set to 20 2018-08-07 12:57:38,507 [myid:5] - INFO [main:FileSnap@83] - Reading snapshot /data/zookeeper/version-2/snapshot.3006d7ef1 2018-08-07 12:57:38,790 [myid:5] - INFO [main:Server@327] - jetty-9.2.18.v20160721 2018-08-07 12:57:38,817 [myid:5] - INFO [main:ContextHandler@744] - Started o.e.j.s.ServletContextHandler@224edc67{/,null,AVAILABLE} 2018-08-07 12:57:38,822 [myid:5] - INFO [main:AbstractConnector@266] - Started ServerConnector@30b8a058{HTTP/1.1}{0.0.0.0:8081} 2018-08-07 12:57:38,823 [myid:5] - INFO [main:Server@379] - Started @1136ms 2018-08-07 12:57:38,823 [myid:5] - INFO [main:JettyAdminServer@112] - Started AdminServer on address 0.0.0.0, port 8081 and command URL /commands 2018-08-07 12:57:38,827 [myid:5] - INFO [QuorumPeerListener:QuorumCnxManager$Listener@854] - My election bind port: srv9904g/10.192.110.51:3888 2018-08-07 12:57:38,835 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):QuorumPeer@1136] - LOOKING 2018-08-07 12:57:38,837 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):FastLeaderElection@893] - New election. My id = 5, proposed zxid=0x3006dc29e 2018-08-07 12:57:38,863 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 2 (n.leader), 0x3006dc29e (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x3 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-07 12:57:38,870 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 5 (n.leader), 0x3006dc29e (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x3 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-07 12:57:38,870 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 2 (n.leader), 0x3006dc29e (n.zxid), 0x0 (n.round), LOOKING (n.state), 2 (n.sid), 0x3 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-07 12:57:38,871 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 5 (n.leader), 0x3006dc29e (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x3 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-07 12:57:38,871 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 5 (n.leader), 0x3006dc29e (n.zxid), 0x1 (n.round), LOOKING (n.state), 5 (n.sid), 0x3 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-07 12:57:38,874 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x3006dc29e (n.zxid), 0x0 (n.round), LOOKING (n.state), 3 (n.sid), 0x3 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-07 12:57:38,875 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 5 (n.leader), 0x3006dc29e (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x3 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-07 12:57:38,881 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 5 (n.leader), 0x3006dc29e (n.zxid), 0x1 (n.round), LOOKING (n.state), 4 (n.sid), 0x3 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-07 12:57:39,081 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id5,name1=replica.5,name2=LeaderElection] 2018-08-07 12:57:39,082 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):QuorumPeer@1224] - LEADING 2018-08-07 12:57:39,085 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Leader@67] - TCP NoDelay set to: true 2018-08-07 12:57:39,085 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Leader@87] - zookeeper.leader.maxConcurrentSnapshots = 10 2018-08-07 12:57:39,085 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Leader@89] - zookeeper.leader.maxConcurrentSnapshotTimeout = 5 2018-08-07 12:57:39,095 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:zookeeper.version=3.5.4-beta-7f51e5b68cf2f80176ff944a9ebd2abbc65e7327, built on 05/11/2018 16:27 GMT 2018-08-07 12:57:39,095 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:host.name=srv9904g.europe.intranet 2018-08-07 12:57:39,095 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.version=1.8.0_171 2018-08-07 12:57:39,095 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.vendor=Oracle Corporation 2018-08-07 12:57:39,095 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.home=/usr/lib/jvm/java-1.8.0-oracle-1.8.0.171-1jpp.1.el7.x86_64/jre 2018-08-07 12:57:39,095 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.class.path=/opt/zookeeper/bin/../build/classes:/opt/zookeeper/bin/../build/lib/*.jar:/opt/zookeeper/bin/../lib/slf4j-log4j12-1.7.25.jar:/opt/zookeeper/bin/../lib/slf4j-api-1.7.25.jar:/opt/zookeeper/bin/../lib/netty-3.10.6.Final.jar:/opt/zookeeper/bin/../lib/log4j-1.2.17.jar:/opt/zookeeper/bin/../lib/jline-2.11.jar:/opt/zookeeper/bin/../lib/jetty-util-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-servlet-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-server-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-security-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-io-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-http-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/javax.servlet-api-3.1.0.jar:/opt/zookeeper/bin/../lib/jackson-mapper-asl-1.9.11.jar:/opt/zookeeper/bin/../lib/jackson-core-asl-1.9.11.jar:/opt/zookeeper/bin/../lib/commons-cli-1.2.jar:/opt/zookeeper/bin/../lib/audience-annotations-0.5.0.jar:/opt/zookeeper/bin/../zookeeper-3.5.4-beta.jar:/opt/zookeeper/bin/../src/java/lib/*.jar:/opt/zookeeper/bin/../conf: 2018-08-07 12:57:39,095 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib 2018-08-07 12:57:39,095 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.io.tmpdir=/tmp 2018-08-07 12:57:39,095 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.compiler= 2018-08-07 12:57:39,096 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.name=Linux 2018-08-07 12:57:39,096 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.arch=amd64 2018-08-07 12:57:39,096 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.version=3.10.0-862.3.3.el7.x86_64 2018-08-07 12:57:39,096 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:user.name=profile 2018-08-07 12:57:39,096 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:user.home=/home/profile 2018-08-07 12:57:39,096 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:user.dir=/ 2018-08-07 12:57:39,096 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.memory.free=918MB 2018-08-07 12:57:39,096 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.memory.max=958MB 2018-08-07 12:57:39,096 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.memory.total=958MB 2018-08-07 12:57:39,097 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):ZooKeeperServer@928] - minSessionTimeout set to 2000 2018-08-07 12:57:39,097 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):ZooKeeperServer@937] - maxSessionTimeout set to 20000 2018-08-07 12:57:39,098 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):ZooKeeperServer@160] - Created server with tickTime 1000 minSessionTimeout 2000 maxSessionTimeout 20000 datadir /data/zookeeper/version-2 snapdir /data/zookeeper/version-2 2018-08-07 12:57:39,099 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Leader@432] - LEADING - LEADER ELECTION TOOK - 17 MS 2018-08-07 12:57:40,078 [myid:5] - INFO [LearnerHandler-/10.192.110.50:53948:LearnerHandler@401] - Follower sid: 2 : info : srv9904f:2888:3888:participant;0.0.0.0:2181 2018-08-07 12:57:40,078 [myid:5] - INFO [LearnerHandler-/10.192.110.49:53830:LearnerHandler@401] - Follower sid: 1 : info : srv9904e:2888:3888:participant;0.0.0.0:2181 2018-08-07 12:57:40,084 [myid:5] - INFO [LearnerHandler-/10.192.110.50:53948:ZKDatabase@295] - On disk txn sync enabled with snapshotSizeFactor 0.33 2018-08-07 12:57:40,085 [myid:5] - INFO [LearnerHandler-/10.192.110.50:53948:LearnerHandler@703] - Synchronizing with Follower sid: 2 maxCommittedLog=0x3006dc29e minCommittedLog=0x3006dc0aa lastProcessedZxid=0x3006dc29e peerLastZxid=0x3006dc29e 2018-08-07 12:57:40,085 [myid:5] - INFO [LearnerHandler-/10.192.110.50:53948:LearnerHandler@747] - Sending DIFF zxid=0x3006dc29e for peer sid: 2 2018-08-07 12:57:40,085 [myid:5] - INFO [LearnerHandler-/10.192.110.49:53830:ZKDatabase@295] - On disk txn sync enabled with snapshotSizeFactor 0.33 2018-08-07 12:57:40,086 [myid:5] - INFO [LearnerHandler-/10.192.110.49:53830:LearnerHandler@703] - Synchronizing with Follower sid: 1 maxCommittedLog=0x3006dc29e minCommittedLog=0x3006dc0aa lastProcessedZxid=0x3006dc29e peerLastZxid=0x3006dc29e 2018-08-07 12:57:40,086 [myid:5] - INFO [LearnerHandler-/10.192.110.49:53830:LearnerHandler@747] - Sending DIFF zxid=0x3006dc29e for peer sid: 1 2018-08-07 12:57:40,086 [myid:5] - INFO [LearnerHandler-/10.194.110.51:33714:LearnerHandler@401] - Follower sid: 3 : info : srv9904h:2888:3888:participant;0.0.0.0:2181 2018-08-07 12:57:40,088 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Leader@1264] - Have quorum of supporters, sids: [ [1, 2, 5] ]; starting up and setting last processed zxid: 0x400000000 2018-08-07 12:57:40,090 [myid:5] - INFO [LearnerHandler-/10.194.110.51:33714:ZKDatabase@295] - On disk txn sync enabled with snapshotSizeFactor 0.33 2018-08-07 12:57:40,090 [myid:5] - INFO [LearnerHandler-/10.194.110.51:33714:LearnerHandler@703] - Synchronizing with Follower sid: 3 maxCommittedLog=0x3006dc29e minCommittedLog=0x3006dc0aa lastProcessedZxid=0x3006dc29e peerLastZxid=0x3006dc29e 2018-08-07 12:57:40,090 [myid:5] - INFO [LearnerHandler-/10.194.110.51:33714:LearnerHandler@747] - Sending DIFF zxid=0x3006dc29e for peer sid: 3 2018-08-07 12:57:40,092 [myid:5] - INFO [LearnerHandler-/10.194.110.52:34990:LearnerHandler@401] - Follower sid: 4 : info : srv9904i:2888:3888:participant;0.0.0.0:2181 2018-08-07 12:57:40,094 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):CommitProcessor@255] - Configuring CommitProcessor with 30 worker threads. 2018-08-07 12:57:40,097 [myid:5] - INFO [LearnerHandler-/10.194.110.52:34990:ZKDatabase@295] - On disk txn sync enabled with snapshotSizeFactor 0.33 2018-08-07 12:57:40,097 [myid:5] - INFO [LearnerHandler-/10.194.110.52:34990:LearnerHandler@703] - Synchronizing with Follower sid: 4 maxCommittedLog=0x3006dc29e minCommittedLog=0x3006dc0aa lastProcessedZxid=0x3006dc29e peerLastZxid=0x3006dc29e 2018-08-07 12:57:40,097 [myid:5] - INFO [LearnerHandler-/10.194.110.52:34990:LearnerHandler@747] - Sending DIFF zxid=0x3006dc29e for peer sid: 4 2018-08-07 12:57:40,099 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):PrepRequestProcessor@99] - zookeeper.skipACL=="yes", ACL checks will be skipped 2018-08-07 12:57:40,100 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):ContainerManager@64] - Using checkIntervalMs=60000 maxPerMinute=10000 2018-08-07 12:57:40,346 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x4006d01b1bc0000 type:create2 cxid:0x1 zxid:0x400000003 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904i.europe.intranet Error:KeeperErrorCode = NodeExists for /GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904i.europe.intranet 2018-08-07 12:57:40,356 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x4006d01b1bc0000 type:create2 cxid:0x90 zxid:0x400000005 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904j.europe.intranet Error:KeeperErrorCode = NodeExists for /GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904j.europe.intranet 2018-08-07 12:57:40,358 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x4006d01b1bc0000 type:create2 cxid:0x92 zxid:0x400000006 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/rw/srv9904h:v7prod Error:KeeperErrorCode = NodeExists for /GROUP_V7PROD/ephemerals/rw/srv9904h:v7prod 2018-08-07 12:57:40,358 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x4006d01b1bc0000 type:create2 cxid:0x93 zxid:0x400000007 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904e.europe.intranet Error:KeeperErrorCode = NodeExists for /GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904e.europe.intranet 2018-08-07 12:57:40,358 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x4006d01b1bc0000 type:create2 cxid:0x94 zxid:0x400000008 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904f.europe.intranet Error:KeeperErrorCode = NodeExists for /GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904f.europe.intranet 2018-08-07 12:57:40,367 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x1006ce75d9c0001 type:create2 cxid:0x8f zxid:0x40000000b txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/rw/srv9904e:v7prod Error:KeeperErrorCode = NodeExists for /GROUP_V7PROD/ephemerals/rw/srv9904e:v7prod 2018-08-07 12:57:40,469 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x2008b4ba2810000 type:create2 cxid:0x8f zxid:0x400000011 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/rw/srv9904j:v7prod Error:KeeperErrorCode = NodeExists for /GROUP_V7PROD/ephemerals/rw/srv9904j:v7prod 2018-08-07 12:57:41,011 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x3008fc0a5e40000 type:create2 cxid:0x1 zxid:0x400000014 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/rw/srv9904i:v7prod Error:KeeperErrorCode = NodeExists for /GROUP_V7PROD/ephemerals/rw/srv9904i:v7prod 2018-08-07 12:57:41,435 [myid:5] - INFO [NIOWorkerThread-4:ZooKeeperServer@1046] - Client attempting to renew session 0x5000000691e0000 at /10.194.110.52:34466 2018-08-07 12:57:41,437 [myid:5] - INFO [NIOWorkerThread-4:ZooKeeperServer@748] - Established session 0x5000000691e0000 with negotiated timeout 20000 for client /10.194.110.52:34466 2018-08-07 12:57:42,072 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x4006d01b1bc0002 type:create2 cxid:0x8f zxid:0x40000001a txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/rw/srv9904f:v7prod Error:KeeperErrorCode = NodeExists for /GROUP_V7PROD/ephemerals/rw/srv9904f:v7prod 2018-08-07 12:57:53,667 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x1006ce75d9c0001 type:setData cxid:0xae zxid:0x400000021 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/data/command/failover_advised Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/data/command/failover_advised 2018-08-07 12:58:00,539 [myid:5] - INFO [SessionTracker:ZooKeeperServer@392] - Expiring session 0x500002dca550000, timeout of 20000ms exceeded 2018-08-07 12:58:00,540 [myid:5] - INFO [SessionTracker:QuorumZooKeeperServer@157] - Submitting global closeSession request for session 0x500002dca550000 2018-08-07 12:58:00,540 [myid:5] - INFO [SessionTracker:ZooKeeperServer@392] - Expiring session 0x100479630560006, timeout of 20000ms exceeded 2018-08-07 12:58:00,540 [myid:5] - INFO [SessionTracker:QuorumZooKeeperServer@157] - Submitting global closeSession request for session 0x100479630560006 2018-08-07 12:58:00,540 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@611] - Processed session termination for sessionid: 0x500002dca550000 2018-08-07 12:58:00,540 [myid:5] - INFO [SessionTracker:ZooKeeperServer@392] - Expiring session 0x40089b0086b0001, timeout of 20000ms exceeded 2018-08-07 12:58:00,540 [myid:5] - INFO [SessionTracker:QuorumZooKeeperServer@157] - Submitting global closeSession request for session 0x40089b0086b0001 2018-08-07 12:58:00,540 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@611] - Processed session termination for sessionid: 0x100479630560006 2018-08-07 12:58:00,540 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@611] - Processed session termination for sessionid: 0x40089b0086b0001 2018-08-07 13:01:24,314 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x4006d01b1bc0000 type:delete cxid:0x269 zxid:0x4000001cb txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904g.europe.intranet Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904g.europe.intranet 2018-08-07 13:04:29,856 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x2008b4ba2810001 type:create2 cxid:0x91 zxid:0x40000045a txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/data/backlog/backlog Error:KeeperErrorCode = NodeExists for /GROUP_V7PROD/data/backlog/backlog 2018-08-07 13:04:29,860 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x2008b4ba2810001 type:create2 cxid:0x92 zxid:0x40000045b txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/data/backlog/timestampsec Error:KeeperErrorCode = NodeExists for /GROUP_V7PROD/data/backlog/timestampsec 2018-08-07 13:04:30,872 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x2008b4ba2810001 type:delete cxid:0xa0 zxid:0x400000464 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/data/srv9904g:v7prod/command Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/data/srv9904g:v7prod/command 2018-08-07 13:04:30,882 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x2008b4ba2810001 type:delete cxid:0xa8 zxid:0x400000465 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/rw/srv9904g:v7prod Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/rw/srv9904g:v7prod 2018-08-07 13:04:30,884 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x2008b4ba2810001 type:delete cxid:0xaa zxid:0x400000466 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/errors/srv9904g:v7prod:MTMCheckFailed Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/errors/srv9904g:v7prod:MTMCheckFailed 2018-08-07 13:04:30,885 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x2008b4ba2810001 type:delete cxid:0xab zxid:0x400000467 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/errors/srv9904g:v7prod:StatusCheckFailed Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/errors/srv9904g:v7prod:StatusCheckFailed 2018-08-07 13:04:30,887 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x2008b4ba2810001 type:delete cxid:0xac zxid:0x400000468 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/errors/srv9904g:v7prod:JNLCheckFailed Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/errors/srv9904g:v7prod:JNLCheckFailed 2018-08-07 13:04:30,888 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x2008b4ba2810001 type:delete cxid:0xad zxid:0x400000469 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/rw/srv9904g:v7prod Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/rw/srv9904g:v7prod 2018-08-07 13:04:30,890 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x2008b4ba2810001 type:delete cxid:0xae zxid:0x40000046a txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/errors/srv9904g:v7prod:MTMCheckFailed Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/errors/srv9904g:v7prod:MTMCheckFailed 2018-08-07 13:04:30,891 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x2008b4ba2810001 type:delete cxid:0xaf zxid:0x40000046b txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/errors/srv9904g:v7prod:StatusCheckFailed Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/errors/srv9904g:v7prod:StatusCheckFailed 2018-08-07 13:04:30,892 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x2008b4ba2810001 type:delete cxid:0xb0 zxid:0x40000046c txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/errors/srv9904g:v7prod:JNLCheckFailed Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/errors/srv9904g:v7prod:JNLCheckFailed 2018-08-07 13:11:21,339 [myid:5] - INFO [srv9904g/10.192.110.51:3888:QuorumCnxManager$Listener@860] - Received connection request /10.194.110.53:59610 2018-08-07 13:11:21,359 [myid:5] - INFO [LearnerHandler-/10.194.110.53:42206:LearnerHandler@401] - Follower sid: 6 : info : srv9904j:2888:3888:observer;0.0.0.0:2181 2018-08-07 13:11:21,363 [myid:5] - INFO [LearnerHandler-/10.194.110.53:42206:ZKDatabase@295] - On disk txn sync enabled with snapshotSizeFactor 0.33 2018-08-07 13:11:21,364 [myid:5] - INFO [LearnerHandler-/10.194.110.53:42206:LearnerHandler@703] - Synchronizing with Follower sid: 6 maxCommittedLog=0x400000aeb minCommittedLog=0x4000008f7 lastProcessedZxid=0x400000aeb peerLastZxid=0x3006dc29e 2018-08-07 13:11:21,364 [myid:5] - INFO [LearnerHandler-/10.194.110.53:42206:ZKDatabase@349] - Txnlog size: 67108880 exceeds sizeLimit: 3638 2018-08-07 13:11:21,366 [myid:5] - INFO [LearnerHandler-/10.194.110.53:42206:LearnerHandler@474] - Sending snapshot last zxid of peer is 0x3006dc29e, zxid of leader is 0x400000aeb, send zxid of db as 0x400000aeb, 1 concurrent snapshots, snapshot was not exempt from throttle 2018-08-07 14:55:02,540 [myid:5] - INFO [SessionTracker:ZooKeeperServer@392] - Expiring session 0x4006d01b1bc0003, timeout of 20000ms exceeded 2018-08-07 14:55:02,540 [myid:5] - INFO [SessionTracker:QuorumZooKeeperServer@157] - Submitting global closeSession request for session 0x4006d01b1bc0003 2018-08-07 14:55:02,540 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@611] - Processed session termination for sessionid: 0x4006d01b1bc0003 2018-08-08 06:55:37,357 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x4006d01b1bc0000 type:delete cxid:0x99c99 zxid:0x40003e093 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904i.europe.intranet Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904i.europe.intranet 2018-08-08 06:55:57,406 [myid:5] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@878] - Got user-level KeeperException when processing sessionid:0x4006d01b1bc0000 type:delete cxid:0x99d69 zxid:0x40003e0e7 txntype:-1 reqpath:n/a Error Path:/GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904g.europe.intranet Error:KeeperErrorCode = NoNode for /GROUP_V7PROD/ephemerals/secondaries/srv9904h:srv9904g.europe.intranet 2018-08-08 08:46:07,521 [myid:] - INFO [main:QuorumPeerConfig@130] - Reading configuration from: /opt/zookeeper/bin/../conf/zoo.cfg 2018-08-08 08:46:07,527 [myid:] - INFO [main:QuorumPeerConfig@366] - clientPort is not set 2018-08-08 08:46:07,528 [myid:] - INFO [main:QuorumPeerConfig@380] - secureClientPort is not set 2018-08-08 08:46:07,547 [myid:5] - INFO [main:ManagedUtil@46] - Log4j found with jmx enabled. 2018-08-08 08:46:07,560 [myid:5] - INFO [main:QuorumPeerMain@141] - Starting quorum peer 2018-08-08 08:46:07,607 [myid:5] - INFO [main:Log@186] - Logging initialized @703ms 2018-08-08 08:46:07,655 [myid:5] - WARN [main:ContextHandler@1339] - o.e.j.s.ServletContextHandler@224edc67{/,null,null} contextPath ends with /* 2018-08-08 08:46:07,655 [myid:5] - WARN [main:ContextHandler@1350] - Empty contextPath 2018-08-08 08:46:07,663 [myid:5] - INFO [main:QuorumPeer@1430] - Local sessions disabled 2018-08-08 08:46:07,664 [myid:5] - INFO [main:QuorumPeer@1441] - Local session upgrading disabled 2018-08-08 08:46:07,664 [myid:5] - INFO [main:QuorumPeer@1408] - tickTime set to 1000 2018-08-08 08:46:07,664 [myid:5] - INFO [main:QuorumPeer@1452] - minSessionTimeout set to 2000 2018-08-08 08:46:07,664 [myid:5] - INFO [main:QuorumPeer@1463] - maxSessionTimeout set to 20000 2018-08-08 08:46:07,664 [myid:5] - INFO [main:QuorumPeer@1478] - initLimit set to 10 2018-08-08 08:46:07,674 [myid:5] - INFO [main:ZKDatabase@117] - zookeeper.snapshotSizeFactor = 0.33 2018-08-08 08:46:07,675 [myid:5] - INFO [main:QuorumPeer@2036] - QuorumPeer communication is not secured! 2018-08-08 08:46:07,675 [myid:5] - INFO [main:QuorumPeer@2065] - quorum.cnxn.threads.size set to 20 2018-08-08 08:46:07,678 [myid:5] - INFO [main:FileSnap@83] - Reading snapshot /data/zookeeper/version-2/snapshot.40003c72b 2018-08-08 08:46:08,012 [myid:5] - INFO [main:Server@327] - jetty-9.2.18.v20160721 2018-08-08 08:46:08,040 [myid:5] - INFO [main:ContextHandler@744] - Started o.e.j.s.ServletContextHandler@224edc67{/,null,AVAILABLE} 2018-08-08 08:46:08,045 [myid:5] - INFO [main:AbstractConnector@266] - Started ServerConnector@30b8a058{HTTP/1.1}{0.0.0.0:8081} 2018-08-08 08:46:08,045 [myid:5] - INFO [main:Server@379] - Started @1143ms 2018-08-08 08:46:08,045 [myid:5] - INFO [main:JettyAdminServer@112] - Started AdminServer on address 0.0.0.0, port 8081 and command URL /commands 2018-08-08 08:46:08,070 [myid:5] - INFO [QuorumPeerListener:QuorumCnxManager$Listener@854] - My election bind port: srv9904g/10.192.110.51:3888 2018-08-08 08:46:08,075 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):QuorumPeer@1136] - LOOKING 2018-08-08 08:46:08,075 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):FastLeaderElection@893] - New election. My id = 5, proposed zxid=0x4000443b8 2018-08-08 08:46:08,088 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0x2 (n.round), LOOKING (n.state), 1 (n.sid), 0x4 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,091 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0x2 (n.round), LOOKING (n.state), 2 (n.sid), 0x4 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,092 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 5 (n.leader), 0x4000443b8 (n.zxid), 0x1 (n.round), LOOKING (n.state), 5 (n.sid), 0x4 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,092 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 1 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,093 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 3 (n.leader), 0x4000443b8 (n.zxid), 0x2 (n.round), LOOKING (n.state), 3 (n.sid), 0x4 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,093 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 5 (n.leader), 0x4000443b8 (n.zxid), 0x2 (n.round), LOOKING (n.state), 5 (n.sid), 0x4 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,093 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 5 (n.leader), 0x4000443b8 (n.zxid), 0x2 (n.round), LOOKING (n.state), 5 (n.sid), 0x4 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,094 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0x2 (n.round), LOOKING (n.state), 4 (n.sid), 0x4 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,094 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 2 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,095 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 1 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,095 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 2 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,100 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 3 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,101 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 3 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,102 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), LEADING (n.state), 4 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,102 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), LEADING (n.state), 4 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 08:46:08,102 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id5,name1=replica.5,name2=LeaderElection] 2018-08-08 08:46:08,103 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):QuorumPeer@1212] - FOLLOWING 2018-08-08 08:46:08,105 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Learner@90] - TCP NoDelay set to: true 2018-08-08 08:46:08,113 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:zookeeper.version=3.5.4-beta-7f51e5b68cf2f80176ff944a9ebd2abbc65e7327, built on 05/11/2018 16:27 GMT 2018-08-08 08:46:08,113 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:host.name=srv9904g.europe.intranet 2018-08-08 08:46:08,113 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.version=1.8.0_171 2018-08-08 08:46:08,113 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.vendor=Oracle Corporation 2018-08-08 08:46:08,113 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.home=/usr/lib/jvm/java-1.8.0-oracle-1.8.0.171-1jpp.1.el7.x86_64/jre 2018-08-08 08:46:08,113 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.class.path=/opt/zookeeper/bin/../build/classes:/opt/zookeeper/bin/../build/lib/*.jar:/opt/zookeeper/bin/../lib/slf4j-log4j12-1.7.25.jar:/opt/zookeeper/bin/../lib/slf4j-api-1.7.25.jar:/opt/zookeeper/bin/../lib/netty-3.10.6.Final.jar:/opt/zookeeper/bin/../lib/log4j-1.2.17.jar:/opt/zookeeper/bin/../lib/jline-2.11.jar:/opt/zookeeper/bin/../lib/jetty-util-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-servlet-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-server-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-security-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-io-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-http-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/javax.servlet-api-3.1.0.jar:/opt/zookeeper/bin/../lib/jackson-mapper-asl-1.9.11.jar:/opt/zookeeper/bin/../lib/jackson-core-asl-1.9.11.jar:/opt/zookeeper/bin/../lib/commons-cli-1.2.jar:/opt/zookeeper/bin/../lib/audience-annotations-0.5.0.jar:/opt/zookeeper/bin/../zookeeper-3.5.4-beta.jar:/opt/zookeeper/bin/../src/java/lib/*.jar:/opt/zookeeper/bin/../conf: 2018-08-08 08:46:08,113 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib 2018-08-08 08:46:08,113 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.io.tmpdir=/tmp 2018-08-08 08:46:08,113 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.compiler= 2018-08-08 08:46:08,114 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.name=Linux 2018-08-08 08:46:08,114 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.arch=amd64 2018-08-08 08:46:08,114 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.version=3.10.0-862.6.3.el7.x86_64 2018-08-08 08:46:08,114 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:user.name=profile 2018-08-08 08:46:08,114 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:user.home=/home/profile 2018-08-08 08:46:08,114 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:user.dir=/ 2018-08-08 08:46:08,114 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.memory.free=908MB 2018-08-08 08:46:08,114 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.memory.max=958MB 2018-08-08 08:46:08,114 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.memory.total=958MB 2018-08-08 08:46:08,115 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):ZooKeeperServer@928] - minSessionTimeout set to 2000 2018-08-08 08:46:08,115 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):ZooKeeperServer@937] - maxSessionTimeout set to 20000 2018-08-08 08:46:08,115 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):ZooKeeperServer@160] - Created server with tickTime 1000 minSessionTimeout 2000 maxSessionTimeout 20000 datadir /data/zookeeper/version-2 snapdir /data/zookeeper/version-2 2018-08-08 08:46:08,115 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Follower@69] - FOLLOWING - LEADER ELECTION TOOK - 13 MS 2018-08-08 08:46:08,277 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Learner@378] - Getting a diff from the leader 0x500000230 2018-08-08 08:46:08,281 [myid:5] - WARN [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Learner@441] - Got zxid 0x500000001 expected 0x1 2018-08-08 08:46:08,303 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Learner@533] - Learner received NEWLEADER message 2018-08-08 08:46:08,307 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Learner@516] - Learner received UPTODATE message 2018-08-08 08:46:08,311 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):CommitProcessor@255] - Configuring CommitProcessor with 30 worker threads. 2018-08-08 08:46:08,402 [myid:5] - WARN [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Follower@125] - Got zxid 0x500000231 expected 0x1 2018-08-08 08:59:17,606 [myid:5] - INFO [srv9904g/10.192.110.51:3888:QuorumCnxManager$Listener@860] - Received connection request /10.194.110.53:54210 2018-08-08 10:59:20,939 [myid:] - INFO [main:QuorumPeerConfig@130] - Reading configuration from: /opt/zookeeper/bin/../conf/zoo.cfg 2018-08-08 10:59:20,944 [myid:] - INFO [main:QuorumPeerConfig@366] - clientPort is not set 2018-08-08 10:59:20,944 [myid:] - INFO [main:QuorumPeerConfig@380] - secureClientPort is not set 2018-08-08 10:59:20,968 [myid:5] - INFO [main:ManagedUtil@46] - Log4j found with jmx enabled. 2018-08-08 10:59:20,981 [myid:5] - INFO [main:QuorumPeerMain@141] - Starting quorum peer 2018-08-08 10:59:21,027 [myid:5] - INFO [main:Log@186] - Logging initialized @846ms 2018-08-08 10:59:21,085 [myid:5] - WARN [main:ContextHandler@1339] - o.e.j.s.ServletContextHandler@224edc67{/,null,null} contextPath ends with /* 2018-08-08 10:59:21,086 [myid:5] - WARN [main:ContextHandler@1350] - Empty contextPath 2018-08-08 10:59:21,098 [myid:5] - INFO [main:QuorumPeer@1430] - Local sessions disabled 2018-08-08 10:59:21,099 [myid:5] - INFO [main:QuorumPeer@1441] - Local session upgrading disabled 2018-08-08 10:59:21,099 [myid:5] - INFO [main:QuorumPeer@1408] - tickTime set to 1000 2018-08-08 10:59:21,099 [myid:5] - INFO [main:QuorumPeer@1452] - minSessionTimeout set to 2000 2018-08-08 10:59:21,099 [myid:5] - INFO [main:QuorumPeer@1463] - maxSessionTimeout set to 20000 2018-08-08 10:59:21,099 [myid:5] - INFO [main:QuorumPeer@1478] - initLimit set to 10 2018-08-08 10:59:21,110 [myid:5] - INFO [main:ZKDatabase@117] - zookeeper.snapshotSizeFactor = 0.33 2018-08-08 10:59:21,111 [myid:5] - INFO [main:QuorumPeer@2036] - QuorumPeer communication is not secured! 2018-08-08 10:59:21,111 [myid:5] - INFO [main:QuorumPeer@2065] - quorum.cnxn.threads.size set to 20 2018-08-08 10:59:21,114 [myid:5] - INFO [main:FileSnap@83] - Reading snapshot /data/zookeeper/version-2/snapshot.40003c72b 2018-08-08 10:59:21,537 [myid:5] - INFO [main:Server@327] - jetty-9.2.18.v20160721 2018-08-08 10:59:21,563 [myid:5] - INFO [main:ContextHandler@744] - Started o.e.j.s.ServletContextHandler@224edc67{/,null,AVAILABLE} 2018-08-08 10:59:21,579 [myid:5] - INFO [main:AbstractConnector@266] - Started ServerConnector@30b8a058{HTTP/1.1}{0.0.0.0:8081} 2018-08-08 10:59:21,579 [myid:5] - INFO [main:Server@379] - Started @1399ms 2018-08-08 10:59:21,582 [myid:5] - INFO [main:JettyAdminServer@112] - Started AdminServer on address 0.0.0.0, port 8081 and command URL /commands 2018-08-08 10:59:21,585 [myid:5] - INFO [QuorumPeerListener:QuorumCnxManager$Listener@854] - My election bind port: srv9904g/10.192.110.51:3888 2018-08-08 10:59:21,594 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):QuorumPeer@1136] - LOOKING 2018-08-08 10:59:21,594 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):FastLeaderElection@893] - New election. My id = 5, proposed zxid=0x500000e21 2018-08-08 10:59:21,605 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 1 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 10:59:21,612 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 2 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 10:59:21,613 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 5 (n.leader), 0x500000e21 (n.zxid), 0x1 (n.round), LOOKING (n.state), 5 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 10:59:21,613 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 1 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 10:59:21,614 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 2 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 10:59:21,614 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 3 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 10:59:21,614 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), LEADING (n.state), 4 (n.sid), 0x5 (n.peerEPoch), LOOKING (my state)2000092bc (n.config version) 2018-08-08 10:59:21,615 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id5,name1=replica.5,name2=LeaderElection] 2018-08-08 10:59:21,615 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):QuorumPeer@1212] - FOLLOWING 2018-08-08 10:59:21,618 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Learner@90] - TCP NoDelay set to: true 2018-08-08 10:59:21,619 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 3 (n.sid), 0x5 (n.peerEPoch), FOLLOWING (my state)2000092bc (n.config version) 2018-08-08 10:59:21,621 [myid:5] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@687] - Notification: 2 (message format version), 4 (n.leader), 0x4000443b8 (n.zxid), 0xffffffffffffffff (n.round), LEADING (n.state), 4 (n.sid), 0x5 (n.peerEPoch), FOLLOWING (my state)2000092bc (n.config version) 2018-08-08 10:59:21,626 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:zookeeper.version=3.5.4-beta-7f51e5b68cf2f80176ff944a9ebd2abbc65e7327, built on 05/11/2018 16:27 GMT 2018-08-08 10:59:21,626 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:host.name=srv9904g.europe.intranet 2018-08-08 10:59:21,626 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.version=1.8.0_171 2018-08-08 10:59:21,626 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.vendor=Oracle Corporation 2018-08-08 10:59:21,626 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.home=/usr/lib/jvm/java-1.8.0-oracle-1.8.0.171-1jpp.1.el7.x86_64/jre 2018-08-08 10:59:21,626 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.class.path=/opt/zookeeper/bin/../build/classes:/opt/zookeeper/bin/../build/lib/*.jar:/opt/zookeeper/bin/../lib/slf4j-log4j12-1.7.25.jar:/opt/zookeeper/bin/../lib/slf4j-api-1.7.25.jar:/opt/zookeeper/bin/../lib/netty-3.10.6.Final.jar:/opt/zookeeper/bin/../lib/log4j-1.2.17.jar:/opt/zookeeper/bin/../lib/jline-2.11.jar:/opt/zookeeper/bin/../lib/jetty-util-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-servlet-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-server-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-security-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-io-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/jetty-http-9.2.18.v20160721.jar:/opt/zookeeper/bin/../lib/javax.servlet-api-3.1.0.jar:/opt/zookeeper/bin/../lib/jackson-mapper-asl-1.9.11.jar:/opt/zookeeper/bin/../lib/jackson-core-asl-1.9.11.jar:/opt/zookeeper/bin/../lib/commons-cli-1.2.jar:/opt/zookeeper/bin/../lib/audience-annotations-0.5.0.jar:/opt/zookeeper/bin/../zookeeper-3.5.4-beta.jar:/opt/zookeeper/bin/../src/java/lib/*.jar:/opt/zookeeper/bin/../conf: 2018-08-08 10:59:21,626 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib 2018-08-08 10:59:21,626 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.io.tmpdir=/tmp 2018-08-08 10:59:21,626 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:java.compiler= 2018-08-08 10:59:21,627 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.name=Linux 2018-08-08 10:59:21,627 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.arch=amd64 2018-08-08 10:59:21,627 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.version=3.10.0-862.6.3.el7.x86_64 2018-08-08 10:59:21,627 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:user.name=profile 2018-08-08 10:59:21,627 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:user.home=/home/profile 2018-08-08 10:59:21,627 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:user.dir=/ 2018-08-08 10:59:21,627 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.memory.free=903MB 2018-08-08 10:59:21,627 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.memory.max=958MB 2018-08-08 10:59:21,627 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Environment@109] - Server environment:os.memory.total=958MB 2018-08-08 10:59:21,628 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):ZooKeeperServer@928] - minSessionTimeout set to 2000 2018-08-08 10:59:21,628 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):ZooKeeperServer@937] - maxSessionTimeout set to 20000 2018-08-08 10:59:21,628 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):ZooKeeperServer@160] - Created server with tickTime 1000 minSessionTimeout 2000 maxSessionTimeout 20000 datadir /data/zookeeper/version-2 snapdir /data/zookeeper/version-2 2018-08-08 10:59:21,629 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Follower@69] - FOLLOWING - LEADER ELECTION TOOK - 14 MS 2018-08-08 10:59:21,849 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Learner@378] - Getting a diff from the leader 0x50000716a 2018-08-08 10:59:21,852 [myid:5] - WARN [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Learner@441] - Got zxid 0x500000e22 expected 0x1 2018-08-08 10:59:21,983 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Learner@533] - Learner received NEWLEADER message 2018-08-08 10:59:21,999 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Learner@516] - Learner received UPTODATE message 2018-08-08 10:59:22,003 [myid:5] - INFO [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):CommitProcessor@255] - Configuring CommitProcessor with 30 worker threads. 2018-08-08 10:59:22,443 [myid:5] - WARN [QuorumPeer[myid=5](plain=/0.0.0.0:2181)(secure=disabled):Follower@125] - Got zxid 0x50000716d expected 0x1