zkServer.sh start启动正常 zkServer.sh status启动异常 解决办法
问题如下:
ZooKeeper JMX enabled by default
Using config: /usr/local/zookeeper/zookeeper-3.4.9/bin/../conf/zoo.cfg
Error contacting service. It is probably not running.
解决办法:肯定是先查日志,不是先百度
百度说的可能出现如下情况
lsof -i:2181
第一,zoo.cfg文件配置出错:dataLogDir指定的目录未被创建;
第二,myid文件中的整数格式不对,或者与zoo.cfg中的server整数不对应
第三,防火墙未关闭;
第四,2181端口被占用;
第五,zoo.cfg文件中主机名出错;
第六,hosts文件中,本机的主机名有两个对应,只需保留主机名和ip地址的映射
解决办法:
zkServer.sh start
启动日志
查看日志 zookeeper.out
发现日志
2018-07-19 17:20:48,250 [myid:] - INFO [main:QuorumPeerConfig@124] - Reading configuration from: /usr/local/zookeeper/zookeeper-3.4.9/bin/../conf/zoo.cfg
2018-07-19 17:20:48,263 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 192.168.121.79 to address: /192.168.121.79
2018-07-19 17:20:48,263 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 192.168.121.78 to address: /192.168.121.78
2018-07-19 17:20:48,263 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 192.168.121.77 to address: /192.168.121.77
2018-07-19 17:20:48,264 [myid:] - INFO [main:QuorumPeerConfig@352] - Defaulting to majority quorums
2018-07-19 17:20:48,266 [myid:1] - INFO [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3
2018-07-19 17:20:48,266 [myid:1] - INFO [main:DatadirCleanupManager@79] - autopurge.purgeInterval set to 0
2018-07-19 17:20:48,266 [myid:1] - INFO [main:DatadirCleanupManager@101] - Purge task is not scheduled.
2018-07-19 17:20:48,275 [myid:1] - INFO [main:QuorumPeerMain@127] - Starting quorum peer
2018-07-19 17:20:48,284 [myid:1] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:2181
2018-07-19 17:20:48,290 [myid:1] - INFO [main:QuorumPeer@1019] - tickTime set to 2000
2018-07-19 17:20:48,290 [myid:1] - INFO [main:QuorumPeer@1039] - minSessionTimeout set to -1
2018-07-19 17:20:48,290 [myid:1] - INFO [main:QuorumPeer@1050] - maxSessionTimeout set to -1
2018-07-19 17:20:48,290 [myid:1] - INFO [main:QuorumPeer@1065] - initLimit set to 10
2018-07-19 17:20:48,300 [myid:1] - INFO [main:FileSnap@83] - Reading snapshot /usr/local/zookeeper/data/version-2/snapshot.700000000
2018-07-19 17:20:48,319 [myid:1] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /192.168.121.77:3888
2018-07-19 17:20:48,326 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:QuorumPeer@774] - LOOKING
2018-07-19 17:20:48,327 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:FastLeaderElection@818] - New election. My id = 1, proposed zxid=0x700000002
2018-07-19 17:20:48,329 [myid:1] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 1 (n.leader), 0x700000002 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x7 (n.peerEpoch) LOOKING (my state)
2018-07-19 17:20:48,331 [myid:1] - INFO [WorkerSender[myid=1]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (2, 1)
2018-07-19 17:20:48,331 [myid:1] - INFO [WorkerSender[myid=1]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (3, 1)
2018-07-19 17:20:48,332 [myid:1] - INFO [/192.168.121.77:3888:QuorumCnxManager$Listener@541] - Received connection request /192.168.121.78:44814
2018-07-19 17:20:48,334 [myid:1] - INFO [/192.168.121.77:3888:QuorumCnxManager$Listener@541] - Received connection request /192.168.121.79:53052
2018-07-19 17:20:48,334 [myid:1] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x20000002c (n.zxid), 0x5 (n.round), FOLLOWING (n.state), 2 (n.sid), 0x7 (n.peerEpoch) LOOKING (my state)
2018-07-19 17:20:48,335 [myid:1] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x20000002c (n.zxid), 0x5 (n.round), FOLLOWING (n.state), 2 (n.sid), 0x7 (n.peerEpoch) LOOKING (my state)
2018-07-19 17:20:48,335 [myid:1] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x20000002c (n.zxid), 0x5 (n.round), LEADING (n.state), 3 (n.sid), 0x7 (n.peerEpoch) LOOKING (my state)
2018-07-19 17:20:48,336 [myid:1] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x20000002c (n.zxid), 0x5 (n.round), LEADING (n.state), 3 (n.sid), 0x7 (n.peerEpoch) FOLLOWING (my state)
2018-07-19 17:20:48,336 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:QuorumPeer@844] - FOLLOWING
2018-07-19 17:20:48,340 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Learner@86] - TCP NoDelay set to: true
2018-07-19 17:20:48,345 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:zookeeper.version=3.4.9-1757313, built on 08/23/2016 06:50 GMT
2018-07-19 17:20:48,345 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:host.name=node1
2018-07-19 17:20:48,345 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.version=1.8.0_121
2018-07-19 17:20:48,346 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.vendor=Oracle Corporation
2018-07-19 17:20:48,346 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.home=/usr/local/jdk1.8.0_121/jre
2018-07-19 17:20:48,346 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.class.path=/usr/local/zookeeper/zookeeper-3.4.9/bin/../build/classes:/usr/local/zookeeper/zookeeper-3.4.9/bin/../build/lib/*.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../lib/slf4j-log4j12-1.6.1.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../lib/slf4j-api-1.6.1.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../lib/netty-3.10.5.Final.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../lib/log4j-1.2.16.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../lib/jline-0.9.94.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../zookeeper-3.4.9.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../src/java/lib/*.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../conf:.:/usr/local/jdk1.8.0_121/lib/dt.jar:/usr/local/jdk1.8.0_121/lib/tools.jar:/usr/local/jdk1.8.0_121/jre/lib
2018-07-19 17:20:48,346 [myid:1] - INFO [QuorumPeer[myid=1]/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
2018-07-19 17:20:48,346 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.io.tmpdir=/tmp
2018-07-19 17:20:48,346 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:java.compiler=<NA>
2018-07-19 17:20:48,346 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.name=Linux
2018-07-19 17:20:48,346 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.arch=amd64
2018-07-19 17:20:48,346 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:os.version=2.6.32-696.16.1.el6.x86_64
2018-07-19 17:20:48,346 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.name=root
2018-07-19 17:20:48,346 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.home=/root
2018-07-19 17:20:48,346 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Environment@100] - Server environment:user.dir=/usr/local/zookeeper/zookeeper-3.4.9/bin
2018-07-19 17:20:48,348 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:ZooKeeperServer@173] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /usr/local/zookeeper/log/version-2 snapdir /usr/local/zookeeper/data/version-2
2018-07-19 17:20:48,348 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Follower@61] - FOLLOWING - LEADER ELECTION TOOK - 21
2018-07-19 17:20:48,350 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:QuorumPeer$QuorumServer@149] - Resolved hostname: 192.168.121.79 to address: /192.168.121.79
2018-07-19 17:20:48,352 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Learner@329] - Getting a snapshot from leader
2018-07-19 17:20:48,358 [myid:1] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:FileTxnSnapLog@240] - Snapshotting: 0x700000000 to /usr/local/zookeeper/data/version-2/snapshot.700000000
日志没啥异常
那咋办,启动是正常的
再次stop后,又启动
zkServer.sh start-foreground
查看也没事异常,很费劲,难道是误报?
那只有该zkServer.sh 启动脚本
status)
# -q is necessary on some versions of linux where nc returns too quickly, and no stat result is output
clientPortAddress=`$GREP "^[[:space:]]*clientPortAddress[^[:alpha:]]" "$ZOOCFG" | sed -e 's/.*=//'`
if ! [ $clientPortAddress ]
then
clientPortAddress="localhost"
fi
clientPort=`$GREP "^[[:space:]]*clientPort[^[:alpha:]]" "$ZOOCFG" | sed -e 's/.*=//'`
STAT=`"$JAVA" "-Dzookeeper.log.dir=${ZOO_LOG_DIR}" "-Dzookeeper.root.logger=${ZOO_LOG4J_PROP}" \
-cp "$CLASSPATH" $JVMFLAGS org.apache.zookeeper.client.FourLetterWordMain \
$clientPortAddress $clientPort srvr 2> /dev/null \
| $GREP Mode`
STAT1=`"$JAVA" "-Dzookeeper.log.dir=${ZOO_LOG_DIR}" "-Dzookeeper.root.logger=${ZOO_LOG4J_PROP}" \
-cp "$CLASSPATH" $JVMFLAGS org.apache.zookeeper.client.FourLetterWordMain \
$clientPortAddress $clientPort srvr 2> test.log \
`
echo "$STAT1"
echo "${ZOO_LOG_DIR}"
echo "$GREP"
echo "$JAVA"
echo "$clientPortAddress $clientPort"
echo "-Dzookeeper.root.logger=${ZOO_LOG4J_PROP}"
echo "$STAT"
if [ "x$STAT" = "x" ]
then
echo "Error contacting service. It is probably not running."
exit 1
else
echo $STAT
exit 0
fi
;;
*)
echo "Usage: $0 {start|start-foreground|stop|restart|status|upgrade|print-cmd}" >&2
esac
我添加的代码如下:
STAT1=`"$JAVA" "-Dzookeeper.log.dir=${ZOO_LOG_DIR}" "-Dzookeeper.root.logger=${ZOO_LOG4J_PROP}" \
-cp "$CLASSPATH" $JVMFLAGS org.apache.zookeeper.client.FourLetterWordMain \
$clientPortAddress $clientPort srvr 2> test.log \
`
echo "$STAT1"
echo "${ZOO_LOG_DIR}"
echo "$GREP"
echo "$JAVA"
echo "$clientPortAddress $clientPort"
echo "-Dzookeeper.root.logger=${ZOO_LOG4J_PROP}"
echo "$STAT"
打印出来,发现还真是存在异常, 查看test.log
有报错
Error: Exception thrown by the agent : java.rmi.server.ExportException: Port already in use: 4888; nested exception is:
java.net.BindException: Address already in use (Bind failed)
查看
咋办
ps -ef|grep zookeeper
netstat -ntlp|grep 4888
发现都是如下程序
root 9750 1 0 17:24 pts/0 00:00:01 /usr/local/jdk1.8.0_121/bin/java -Dzookeeper.log.dir=. -Dzookeeper.root.logger=INFO,CONSOLE -cp /usr/local/zookeeper/zookeeper-3.4.9/bin/../build/classes:/usr/local/zookeeper/zookeeper-3.4.9/bin/../build/lib/*.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../lib/slf4j-log4j12-1.6.1.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../lib/slf4j-api-1.6.1.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../lib/netty-3.10.5.Final.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../lib/log4j-1.2.16.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../lib/jline-0.9.94.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../zookeeper-3.4.9.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../src/java/lib/*.jar:/usr/local/zookeeper/zookeeper-3.4.9/bin/../conf:.:/usr/local/jdk1.8.0_121/lib/dt.jar:/usr/local/jdk1.8.0_121/lib/tools.jar:/usr/local/jdk1.8.0_121/jre/lib -Djava.rmi.server.hostname=192.168.121.77 -Dcom.sun.management.jmxremote.port=4888 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.local.only=false org.apache.zookeeper.server.quorum.QuorumPeerMain /usr/local/zookeeper/zookeeper-3.4.9/bin/../conf/zoo.cfg
可以看到 jmxremote 对应的就是 4888发现脚本中还真有 4888 这个东西 , 那就 把端口改了呗
将 zkServer.sh 脚本
SERVER_JVMFLAGS="-Djava.rmi.server.hostname=192.168.121.78
-Dcom.sun.management.jmxremote.port=4888
-Dcom.sun.management.jmxremote.authenticate=false
-Dcom.sun.management.jmxremote.ssl=false"
4888修改成 其他端口,即可启动正常