Zookeeper automatically shuts down once I run command for kafka server

Question

I am struggling with a very strange issue. This was working before without no issues.

I have to start Zookeeper and Kafka. For that I do following:

1. nohup bin/zookeeper-server-start.sh config/zookeeper.properties &

After this when I run jps command : I can see QuaorumPeerMain as one process, that is for Zookeeper.

Now I run 2. nohup bin/kafka-server-start.sh config/server.properties &

After this, when I run JPS, process for zookeeper is also gone and it shut down automatically.

log :

[2018-07-25 01:31:21,832] INFO Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib (org.apache.zookeeper.ZooKeeper)
[2018-07-25 01:31:21,832] INFO Client environment:java.io.tmpdir=/tmp (org.apache.zookeeper.ZooKeeper)
[2018-07-25 01:31:21,832] INFO Client environment:java.compiler=<NA> (org.apache.zookeeper.ZooKeeper)
[2018-07-25 01:31:21,832] INFO Client environment:os.name=Linux (org.apache.zookeeper.ZooKeeper)
[2018-07-25 01:31:21,832] INFO Client environment:os.arch=amd64 (org.apache.zookeeper.ZooKeeper)
[2018-07-25 01:31:21,832] INFO Client environment:os.version=3.10.0-862.3.3.el7.x86_64 (org.apache.zookeeper.ZooKeeper)
[2018-07-25 01:31:21,832] INFO Client environment:user.name=kumar.shorav (org.apache.zookeeper.ZooKeeper)
[2018-07-25 01:31:21,832] INFO Client environment:user.home=/home/kumar.shorav (org.apache.zookeeper.ZooKeeper)
[2018-07-25 01:31:21,832] INFO Client environment:user.dir=/app/opt/kafka_2.10-0.10.2.1 (org.apache.zookeeper.ZooKeeper)
[2018-07-25 01:31:21,833] INFO Initiating client connection, connectString=localhost:2181 sessionTimeout=6000 watcher=org.I0Itec.zkclient.ZkClient@8dbdac1 (org.apache.zookeeper.ZooKeeper)
[2018-07-25 01:31:21,849] INFO Waiting for keeper state SyncConnected (org.I0Itec.zkclient.ZkClient)
[2018-07-25 01:31:21,852] INFO Opening socket connection to server localhost.localdomain/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
[2018-07-25 01:31:21,859] INFO Socket connection established to localhost.localdomain/127.0.0.1:2181, initiating session (org.apache.zookeeper.ClientCnxn)
[2018-07-25 01:31:21,862] INFO Accepted socket connection from /127.0.0.1:38370 (org.apache.zookeeper.server.NIOServerCnxnFactory)
[2018-07-25 01:31:21,870] INFO Client attempting to establish new session at /127.0.0.1:38370 (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:31:21,871] INFO Creating new log file: log.181 (org.apache.zookeeper.server.persistence.FileTxnLog)
[2018-07-25 01:31:21,874] ERROR Severe unrecoverable error, from thread : SyncThread:0 (org.apache.zookeeper.server.ZooKeeperCriticalThread)
java.io.FileNotFoundException: /tmp/zookeeper/version-2/log.181 (Permission denied)
        at java.io.FileOutputStream.open0(Native Method)
        at java.io.FileOutputStream.open(FileOutputStream.java:270)
        at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
        at java.io.FileOutputStream.<init>(FileOutputStream.java:162)
        at org.apache.zookeeper.server.persistence.FileTxnLog.append(FileTxnLog.java:209)
        at org.apache.zookeeper.server.persistence.FileTxnSnapLog.append(FileTxnSnapLog.java:314)
        at org.apache.zookeeper.server.ZKDatabase.append(ZKDatabase.java:470)
        at org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcessor.java:140)
[2018-07-25 01:31:21,877] INFO Thread SyncThread:0 exits, error code 1 (org.apache.zookeeper.server.ZooKeeperServerListenerImpl)
[2018-07-25 01:31:21,877] INFO SyncRequestProcessor exited! (org.apache.zookeeper.server.SyncRequestProcessor)
[2018-07-25 01:31:21,878] INFO Closed socket connection for client /127.0.0.1:38370 which had sessionid 0x164d01e0a460000 (org.apache.zookeeper.server.NIOServerCnxn)
[2018-07-25 01:31:21,879] INFO Unable to read additional data from server sessionid 0x0, likely server has closed socket, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
[2018-07-25 01:31:21,879] INFO NIOServerCnxn factory exited run method (org.apache.zookeeper.server.NIOServerCnxnFactory)
[2018-07-25 01:31:21,880] INFO shutting down (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:31:21,880] INFO Shutting down (org.apache.zookeeper.server.SessionTrackerImpl)
[2018-07-25 01:31:21,881] INFO Shutting down (org.apache.zookeeper.server.PrepRequestProcessor)
[2018-07-25 01:31:21,881] INFO Shutting down (org.apache.zookeeper.server.SyncRequestProcessor)
[2018-07-25 01:31:21,881] INFO PrepRequestProcessor exited loop! (org.apache.zookeeper.server.PrepRequestProcessor)
[2018-07-25 01:31:21,881] INFO shutdown of request processor complete (org.apache.zookeeper.server.FinalRequestProcessor)
[2018-07-25 01:31:21,881] INFO Exiting normally (org.apache.zookeeper.server.ZooKeeperServerMain)
[2018-07-25 01:31:23,914] INFO Opening socket connection to server localhost.localdomain/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)

[2018-07-25 01:51:13,467] INFO Server environment:java.io.tmpdir=/tmp (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:13,467] INFO Server environment:java.compiler=<NA> (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:13,467] INFO Server environment:os.name=Linux (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:13,468] INFO Server environment:os.arch=amd64 (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:13,468] INFO Server environment:os.version=3.10.0-862.3.3.el7.x86_64 (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:13,468] INFO Server environment:user.name=kumar.shorav (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:13,468] INFO Server environment:user.home=/home/kumar.shorav (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:13,468] INFO Server environment:user.dir=/app/opt/kafka_2.10-0.10.2.1 (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:13,477] INFO tickTime set to 3000 (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:13,477] INFO minSessionTimeout set to -1 (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:13,477] INFO maxSessionTimeout set to -1 (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:13,489] INFO binding to port 0.0.0.0/0.0.0.0:2181 (org.apache.zookeeper.server.NIOServerCnxnFactory)
[2018-07-25 01:51:41,099] INFO Accepted socket connection from /127.0.0.1:40262 (org.apache.zookeeper.server.NIOServerCnxnFactory)
[2018-07-25 01:51:41,107] INFO Client attempting to establish new session at /127.0.0.1:40262 (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:41,108] INFO Creating new log file: log.181 (org.apache.zookeeper.server.persistence.FileTxnLog)
[2018-07-25 01:51:41,111] ERROR Severe unrecoverable error, from thread : SyncThread:0 (org.apache.zookeeper.server.ZooKeeperCriticalThread)
java.io.FileNotFoundException: /tmp/zookeeper/version-2/log.181 (Permission denied)
        at java.io.FileOutputStream.open0(Native Method)
        at java.io.FileOutputStream.open(FileOutputStream.java:270)
        at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
        at java.io.FileOutputStream.<init>(FileOutputStream.java:162)
        at org.apache.zookeeper.server.persistence.FileTxnLog.append(FileTxnLog.java:209)
        at org.apache.zookeeper.server.persistence.FileTxnSnapLog.append(FileTxnSnapLog.java:314)
        at org.apache.zookeeper.server.ZKDatabase.append(ZKDatabase.java:470)
        at org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcessor.java:140)
[2018-07-25 01:51:41,113] INFO Thread SyncThread:0 exits, error code 1 (org.apache.zookeeper.server.ZooKeeperServerListenerImpl)
[2018-07-25 01:51:41,113] INFO SyncRequestProcessor exited! (org.apache.zookeeper.server.SyncRequestProcessor)
[2018-07-25 01:51:41,114] INFO Closed socket connection for client /127.0.0.1:40262 which had sessionid 0x164d034b9130000 (org.apache.zookeeper.server.NIOServerCnxn)
[2018-07-25 01:51:41,114] INFO NIOServerCnxn factory exited run method (org.apache.zookeeper.server.NIOServerCnxnFactory)
[2018-07-25 01:51:41,115] INFO shutting down (org.apache.zookeeper.server.ZooKeeperServer)
[2018-07-25 01:51:41,115] INFO Shutting down (org.apache.zookeeper.server.SessionTrackerImpl)
[2018-07-25 01:51:41,115] INFO Shutting down (org.apache.zookeeper.server.PrepRequestProcessor)
[2018-07-25 01:51:41,115] INFO Shutting down (org.apache.zookeeper.server.SyncRequestProcessor)
[2018-07-25 01:51:41,115] INFO PrepRequestProcessor exited loop! (org.apache.zookeeper.server.PrepRequestProcessor)
[2018-07-25 01:51:41,115] INFO shutdown of request processor complete (org.apache.zookeeper.server.FinalRequestProcessor)
[2018-07-25 01:51:41,116] INFO Exiting normally (org.apache.zookeeper.server.ZooKeeperServerMain)

I am not table to figure out why this is suddenly comes in. Please take a look and help me out.

Answer 1

If you look at your logs closely, specifically, java.io.FileNotFoundException: /tmp/zookeeper/version-2/log.181 (Permission denied) it talks about dataDir directory permission change. FYI, dataDir is the directory snapshot which you have specified in zookeeper.properties, I guess in your case it is: /tmp/zookeeper/... something.

Can you check on the linux/ putty as to what permissions are granted for this folder, looks like the permissions have changed which is causing the mentioned issue. Let me know if this worked for you. Thanks!