Tag Archives: zookeeper start error

An error is reported when zookeeper starts (the data directory permission is incorrect)

Zookeeper startup error log:

2016-11-16 11:19:43,880 [myid:3] - INFO  [WorkerReceiver[myid=3]:FastLeaderElection@542] - Notification: 3 (n.leader), 0x200111a88 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x2 (n.peerEPoch), LOOKING (my state)
2016-11-16 11:19:43,883 [myid:3] - INFO  [WorkerReceiver[myid=3]:FastLeaderElection@542] - Notification: 2 (n.leader), 0x200111a88 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x2 (n.peerEPoch), LOOKING (my state)
2016-11-16 11:19:43,886 [myid:3] - INFO  [WorkerReceiver[myid=3]:FastLeaderElection@542] - Notification: 3 (n.leader), 0x200111a88 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x2 (n.peerEPoch), LOOKING (my state)
2016-11-16 11:19:44,089 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:QuorumPeer@750] - LEADING
2016-11-16 11:19:44,093 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Leader@59] - TCP NoDelay set to: true
2016-11-16 11:19:44,097 [myid:3] - INFO  [node03/172.16.145.113:3888:QuorumCnxManager$Listener@493] - Received connection request /172.16.145.111:43715
2016-11-16 11:19:44,101 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:zookeeper.version=3.4.5-cdh5.3.0--1, built on 12/17/2014 02:55 GMT
2016-11-16 11:19:44,101 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:host.name=node03
2016-11-16 11:19:44,101 [myid:3] - INFO  [WorkerReceiver[myid=3]:FastLeaderElection@542] - Notification: 1 (n.leader), 0x200111a88 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x2 (n.peerEPoch), LEADING (my state)
2016-11-16 11:19:44,101 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.version=1.7.0_71
2016-11-16 11:19:44,101 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.vendor=Oracle Corporation
2016-11-16 11:19:44,101 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.home=/usr/java/jdk1.7.0_71/jre
2016-11-16 11:19:44,102 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.class.path=/usr/lib/zookeeper/bin/../build/classes:/usr/lib/zookeeper/bin/../build/lib/*.jar:/usr/lib/zookeeper/bin/../lib/slf4j-log4j12.jar:/usr/lib/zookeeper/bin/../lib/slf4j-log4j12-1.7.5.jar:/usr/lib/zookeeper/bin/../lib/slf4j-api-1.7.5.jar:/usr/lib/zookeeper/bin/../lib/netty-3.2.2.Final.jar:/usr/lib/zookeeper/bin/../lib/log4j-1.2.16.jar:/usr/lib/zookeeper/bin/../lib/jline-0.9.94.jar:/usr/lib/zookeeper/bin/../zookeeper-3.4.5-cdh5.3.0.jar:/usr/lib/zookeeper/bin/../src/java/lib/*.jar:/etc/zookeeper/conf::/etc/zookeeper/conf:/usr/lib/zookeeper/zookeeper-3.4.5-cdh5.3.0.jar:/usr/lib/zookeeper/zookeeper.jar:/usr/lib/zookeeper/lib/netty-3.2.2.Final.jar:/usr/lib/zookeeper/lib/log4j-1.2.16.jar:/usr/lib/zookeeper/lib/slf4j-log4j12-1.7.5.jar:/usr/lib/zookeeper/lib/slf4j-api-1.7.5.jar:/usr/lib/zookeeper/lib/jline-0.9.94.jar:/usr/lib/zookeeper/lib/slf4j-log4j12.jar
2016-11-16 11:19:44,102 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
2016-11-16 11:19:44,102 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.io.tmpdir=/tmp
2016-11-16 11:19:44,102 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.compiler=<NA>
2016-11-16 11:19:44,102 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.name=Linux
2016-11-16 11:19:44,102 [myid:3] - INFO  [WorkerReceiver[myid=3]:FastLeaderElection@542] - Notification: 3 (n.leader), 0x200111a88 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x2 (n.peerEPoch), LEADING (my state)
2016-11-16 11:19:44,102 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.arch=amd64
2016-11-16 11:19:44,103 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.version=2.6.32-504.el6.x86_64
2016-11-16 11:19:44,103 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.name=zookeeper
2016-11-16 11:19:44,103 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.home=/var/lib/zookeeper
2016-11-16 11:19:44,103 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.dir=/
2016-11-16 11:19:44,105 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:ZooKeeperServer@162] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /var/lib/zookeeper/version-2 snapdir /var/lib/zookeeper/version-2
2016-11-16 11:19:44,106 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:Leader@348] - LEADING - LEADER ELECTION TOOK - 243
2016-11-16 11:19:44,120 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:FileSnap@83] - Reading snapshot /var/lib/zookeeper/version-2/snapshot.200106cdb
2016-11-16 11:19:44,511 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:FileTxnSnapLog@273] - Snapshotting: 0x200111a88 to /var/lib/zookeeper/version-2/snapshot.200111a88
2016-11-16 11:19:44,511 [myid:3] - ERROR [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:ZooKeeperServer@272] - Severe unrecoverable error, exiting
java.io.FileNotFoundException: /var/lib/zookeeper/version-2/snapshot.200111a88 (Permission denied)
       at java.io.FileOutputStream.open(Native Method)
       at java.io.FileOutputStream.<init>(FileOutputStream.java:221)
       at java.io.FileOutputStream.<init>(FileOutputStream.java:171)
       at org.apache.zookeeper.server.persistence.FileSnap.serialize(FileSnap.java:225)
       at org.apache.zookeeper.server.persistence.FileTxnSnapLog.save(FileTxnSnapLog.java:275)
       at org.apache.zookeeper.server.ZooKeeperServer.takeSnapshot(ZooKeeperServer.java:270)
       at org.apache.zookeeper.server.ZooKeeperServer.loadData(ZooKeeperServer.java:265)
       at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:357)
       at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:753)
2016-11-16 11:58:48,309 [myid:] - INFO  [main:QuorumPeerConfig@101] - Reading configuration from: /etc/zookeeper/conf/zoo.cfg
2016-11-16 11:58:48,316 [myid:] - INFO  [main:QuorumPeerConfig@334] - Defaulting to majority quorums
2016-11-16 11:58:48,322 [myid:3] - INFO  [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3
2016-11-16 11:58:48,322 [myid:3] - INFO  [main:DatadirCleanupManager@79] - autopurge.purgeInterval set to 0
2016-11-16 11:58:48,323 [myid:3] - INFO  [main:DatadirCleanupManager@101] - Purge task is not scheduled.
2016-11-16 11:58:48,338 [myid:3] - INFO  [main:QuorumPeerMain@132] - Starting quorum peer
2016-11-16 11:58:48,352 [myid:3] - INFO  [main:NIOServerCnxnFactory@94] - binding to port 0.0.0.0/0.0.0.0:2181
2016-11-16 11:58:48,371 [myid:3] - INFO  [main:QuorumPeer@913] - tickTime set to 2000
2016-11-16 11:58:48,371 [myid:3] - INFO  [main:QuorumPeer@933] - minSessionTimeout set to -1
2016-11-16 11:58:48,371 [myid:3] - INFO  [main:QuorumPeer@944] - maxSessionTimeout set to -1
2016-11-16 11:58:48,372 [myid:3] - INFO  [main:QuorumPeer@959] - initLimit set to 10
2016-11-16 11:58:48,392 [myid:3] - INFO  [main:FileSnap@83] - Reading snapshot /var/lib/zookeeper/version-2/snapshot.200106cdb
2016-11-16 11:58:49,556 [myid:3] - INFO  [Thread-1:QuorumCnxManager$Listener@486] - My election bind port: 0.0.0.0/0.0.0.0:3888
2016-11-16 11:58:49,570 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:QuorumPeer@670] - LOOKING
2016-11-16 11:58:49,572 [myid:3] - INFO  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:FastLeaderElection@740] - New election. My id =  3, proposed zxid=0x200111a88
2016-11-16 11:58:49,578 [myid:3] - WARN  [WorkerSender[myid=3]:QuorumCnxManager@368] - Cannot open channel to 1 at election address node01/172.16.145.111: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.java: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(QuorumCnxManager.java:354)
       at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:327)
       at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:393)
       at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:365)
       at java.lang.Thread.run(Thread.java:745)

 

Solution: change the owner of the dataDir directory and the files in the directory to the zookeeper user and zookeeper user group

Execute command: chown – R zookeeper: zookeeper/var/lib/zookeeper

[root@node03 zookeeper]# chown -R  zookeeper:zookeeper /var/lib/zookeeper
[root@node03 zookeeper]# ls -l /var/lib/zookeeper
total 16
-rw-r--r--. 1 zookeeper zookeeper    2 Nov 13 21:20 myid
drwxr-xr-x. 2 zookeeper zookeeper 4096 Nov 16 12:23 version-2
-rw-r--r--. 1 zookeeper zookeeper 1055 Nov 13 21:20 zookeeper.out
-rw-r--r--. 1 zookeeper zookeeper    4 Nov 13 21:20 zookeeper_server.pid
[root@node03 zookeeper]# ls -l /var/lib/zookeeper/version-2/
total 114016
-rw-r--r--. 1 zookeeper zookeeper        1 Nov 16 12:22 acceptedEpoch
-rw-r--r--. 1 zookeeper zookeeper        1 Nov 16 12:22 currentEpoch
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 15 15:57 log.200000001
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 15 17:24 log.20000d912
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 15 18:38 log.200021e5b
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 15 19:39 log.200032bd2
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 15 21:02 log.200040925
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 15 22:03 log.200053776
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 15 23:39 log.200061578
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 16 00:34 log.2000771e7
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 16 01:57 log.200083bd3
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 16 03:14 log.200096a85
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 16 04:53 log.2000a84e4
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 16 06:12 log.2000becbc
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 16 07:45 log.2000d0c68
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 16 08:58 log.2000e60a1
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 16 10:09 log.2000f6a29
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 16 11:01 log.200106cdd
-rw-r--r--. 1 zookeeper zookeeper 67108880 Nov 16 12:32 log.300000001
-rw-r--r--. 1 zookeeper zookeeper      296 Nov 13 22:34 snapshot.100000000
-rw-r--r--. 1 zookeeper zookeeper     1419 Nov 15 15:57 snapshot.20000d910
-rw-r--r--. 1 zookeeper zookeeper     1594 Nov 15 17:24 snapshot.200021e5c
-rw-r--r--. 1 zookeeper zookeeper     1594 Nov 15 18:38 snapshot.200032bd3
-rw-r--r--. 1 zookeeper zookeeper     1606 Nov 15 19:39 snapshot.200040928
-rw-r--r--. 1 zookeeper zookeeper     1606 Nov 15 21:02 snapshot.200053774
-rw-r--r--. 1 zookeeper zookeeper     1771 Nov 15 22:03 snapshot.200061576
-rw-r--r--. 1 zookeeper zookeeper     1594 Nov 15 23:39 snapshot.2000771e7
-rw-r--r--. 1 zookeeper zookeeper     1594 Nov 16 00:34 snapshot.200083bd2
-rw-r--r--. 1 zookeeper zookeeper     1606 Nov 16 01:57 snapshot.200096a83
-rw-r--r--. 1 zookeeper zookeeper     1594 Nov 16 03:14 snapshot.2000a84e4
-rw-r--r--. 1 zookeeper zookeeper     1771 Nov 16 04:53 snapshot.2000becbb
-rw-r--r--. 1 zookeeper zookeeper     1771 Nov 16 06:12 snapshot.2000d0c66
-rw-r--r--. 1 zookeeper zookeeper     1771 Nov 16 07:45 snapshot.2000e60a1
-rw-r--r--. 1 zookeeper zookeeper     1771 Nov 16 08:58 snapshot.2000f6a29
-rw-r--r--. 1 zookeeper zookeeper     1606 Nov 16 10:09 snapshot.200106cdb
-rw-r--r--. 1 zookeeper zookeeper     1395 Nov 16 12:22 snapshot.200111a88

Restart and Done!