由于无法读取database,zookeeper启动失败
2020-03-23 19:34
218 查看
最近我们的集群状态异常,发现启动zk的时候一直失败,看了日志是真的心酸,5s挂机,这要是在开黑,分分钟被举报了,一开始真的没想懂启动zk为什么这么难,而且很稳定的在5s左右失败,通过时间可以判断这个进程还没有完全启动,在这个时间段内,顶多就是在
init状态
[root@ZYC3-AQGK-LJCL-SRV05 deployer]# systemctl status zookeeper ● zookeeper.service - ZooKeeper Service Loaded: loaded (/etc/systemd/system/zookeeper.service; enabled; vendor preset: disabled) Active: active (running) since Mon 2020-03-23 11:29:21 CST; 4s ago Docs: http://zookeeper.apache.org Process: 31011 ExecStop=/opt/zookeeper/zookeeper-prod/bin/zkServer.sh stop /opt/zookeeper/zookeeper-prod/conf/zoo.cfg (code=exited, status=0/SUCCESS) Process: 31129 ExecStart=/opt/zookeeper/zookeeper-prod/bin/zkServer.sh start /opt/zookeeper/zookeeper-prod/conf/zoo.cfg (code=exited, status=0/SUCCESS) Main PID: 31138 (java) CGroup: /system.slice/zookeeper.service └─31138 java -Dzookeeper.log.dir=. -Dzookeeper.root.logger=INFO,CONSOLE -cp /opt/zookeeper/zookeeper-prod/bin/../build/classes:/opt/zookeeper/zookeeper-prod/bin/../build/lib/*.jar:/opt/zookeeper/zoo... Mar 23 11:29:20 ZYC3-AQGK-LJCL-SRV05 systemd[1]: Starting ZooKeeper Service... Mar 23 11:29:20 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[31129]: ZooKeeper JMX enabled by default Mar 23 11:29:20 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[31129]: Using config: /opt/zookeeper/zookeeper-prod/conf/zoo.cfg Mar 23 11:29:21 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[31129]: Starting zookeeper ... STARTED Mar 23 11:29:21 ZYC3-AQGK-LJCL-SRV05 systemd[1]: Started ZooKeeper Service. [root@ZYC3-AQGK-LJCL-SRV05 deployer]# systemctl status zookeeper ● zookeeper.service - ZooKeeper Service Loaded: loaded (/etc/systemd/system/zookeeper.service; enabled; vendor preset: disabled) Active: active (running) since Mon 2020-03-23 11:29:21 CST; 5s ago Docs: http://zookeeper.apache.org Process: 31011 ExecStop=/opt/zookeeper/zookeeper-prod/bin/zkServer.sh stop /opt/zookeeper/zookeeper-prod/conf/zoo.cfg (code=exited, status=0/SUCCESS) Process: 31129 ExecStart=/opt/zookeeper/zookeeper-prod/bin/zkServer.sh start /opt/zookeeper/zookeeper-prod/conf/zoo.cfg (code=exited, status=0/SUCCESS) Main PID: 31138 (java) CGroup: /system.slice/zookeeper.service └─31138 java -Dzookeeper.log.dir=. -Dzookeeper.root.logger=INFO,CONSOLE -cp /opt/zookeeper/zookeeper-prod/bin/../build/classes:/opt/zookeeper/zookeeper-prod/bin/../build/lib/*.jar:/opt/zookeeper/zoo... Mar 23 11:29:20 ZYC3-AQGK-LJCL-SRV05 systemd[1]: Starting ZooKeeper Service... Mar 23 11:29:20 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[31129]: ZooKeeper JMX enabled by default Mar 23 11:29:20 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[31129]: Using config: /opt/zookeeper/zookeeper-prod/conf/zoo.cfg Mar 23 11:29:21 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[31129]: Starting zookeeper ... STARTED Mar 23 11:29:21 ZYC3-AQGK-LJCL-SRV05 systemd[1]: Started ZooKeeper Service. [root@ZYC3-AQGK-LJCL-SRV05 deployer]# systemctl status zookeeper ● zookeeper.service - ZooKeeper Service Loaded: loaded (/etc/systemd/system/zookeeper.service; enabled; vendor preset: disabled) Active: failed (Result: exit-code) since Mon 2020-03-23 11:29:26 CST; 706ms ago Docs: http://zookeeper.apache.org Process: 31225 ExecStop=/opt/zookeeper/zookeeper-prod/bin/zkServer.sh stop /opt/zookeeper/zookeeper-prod/conf/zoo.cfg (code=exited, status=0/SUCCESS) Process: 31129 ExecStart=/opt/zookeeper/zookeeper-prod/bin/zkServer.sh start /opt/zookeeper/zookeeper-prod/conf/zoo.cfg (code=exited, status=0/SUCCESS) Main PID: 31138 (code=exited, status=1/FAILURE) Mar 23 11:29:20 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[31129]: Using config: /opt/zookeeper/zookeeper-prod/conf/zoo.cfg Mar 23 11:29:21 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[31129]: Starting zookeeper ... STARTED Mar 23 11:29:21 ZYC3-AQGK-LJCL-SRV05 systemd[1]: Started ZooKeeper Service. Mar 23 11:29:26 ZYC3-AQGK-LJCL-SRV05 systemd[1]: zookeeper.service: main process exited, code=exited, status=1/FAILURE Mar 23 11:29:26 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[31225]: ZooKeeper JMX enabled by default Mar 23 11:29:26 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[31225]: Using config: /opt/zookeeper/zookeeper-prod/conf/zoo.cfg Mar 23 11:29:26 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[31225]: Stopping zookeeper ... /opt/zookeeper/zookeeper-prod/bin/zkServer.sh: 第 182 行:kill: (31138) - 没有那个进程 Mar 23 11:29:26 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[31225]: STOPPED Mar 23 11:29:26 ZYC3-AQGK-LJCL-SRV05 systemd[1]: Unit zookeeper.service entered failed state. Mar 23 11:29:26 ZYC3-AQGK-LJCL-SRV05 systemd[1]: zookeeper.service failed.
看到日志中提到
/opt/zookeeper/zookeeper-prod/conf/zoo.cfg所以就去这个目录下看看有没有什么值得挖掘的内容。毕竟
conf可以猜测是一个配置文件夹,讲道理应该是有
log或者
output之类的文件夹,里面存放着运行日志,特别是
error日志,按照这个思路就可以进行相关的排查了。
之后发现
/opt/zookeeper/zookeeper-prod/bin目录中有个
zookeeper.out文件,这个是执行的细节,可以看下内容,然后cat一下,问题就很明朗了
2020-03-23 11:36:58,799 [myid:] - INFO [main:QuorumPeerConfig@136] - Reading configuration from: /opt/zookeeper/zookeeper-prod/bin/../conf/zoo.cfg 2020-03-23 11:36:58,814 [myid:] - INFO [main:QuorumPeer$QuorumServer@184] - Resolved hostname: 10.153.115.26 to address: /10.153.115.26 2020-03-23 11:36:58,815 [myid:] - INFO [main:QuorumPeer$QuorumServer@184] - Resolved hostname: 10.153.115.25 to address: /10.153.115.25 2020-03-23 11:36:58,816 [myid:] - INFO [main:QuorumPeer$QuorumServer@184] - Resolved hostname: 10.153.115.24 to address: /10.153.115.24 2020-03-23 11:36:58,816 [myid:] - INFO [main:QuorumPeer$QuorumServer@184] - Resolved hostname: 10.153.115.29 to address: /10.153.115.29 2020-03-23 11:36:58,816 [myid:] - INFO [main:QuorumPeer$QuorumServer@184] - Resolved hostname: 10.153.115.28 to address: /10.153.115.28 2020-03-23 11:36:58,816 [myid:] - INFO [main:QuorumPeer$QuorumServer@184] - Resolved hostname: 10.153.115.27 to address: /10.153.115.27 2020-03-23 11:36:58,816 [myid:] - WARN [main:QuorumPeerConfig@354] - Non-optimial configuration, consider an odd number of servers. 2020-03-23 11:36:58,816 [myid:] - INFO [main:QuorumPeerConfig@398] - Defaulting to majority quorums 2020-03-23 11:36:58,821 [myid:5] - INFO [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3 2020-03-23 11:36:58,821 [myid:5] - INFO [main:DatadirCleanupManager@79] - autopurge.purgeInterval set to 24 2020-03-23 11:36:58,822 [myid:5] - INFO [PurgeTask:DatadirCleanupManager$PurgeTask@138] - Purge task started. 2020-03-23 11:36:58,837 [myid:5] - INFO [PurgeTask:DatadirCleanupManager$PurgeTask@144] - Purge task completed. 2020-03-23 11:36:58,839 [myid:5] - INFO [main:QuorumPeerMain@130] - Starting quorum peer 2020-03-23 11:36:58,849 [myid:5] - INFO [main:ServerCnxnFactory@117] - Using org.apache.zookeeper.server.NIOServerCnxnFactory as server connection factory 2020-03-23 11:36:58,856 [myid:5] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:2181 2020-03-23 11:36:58,861 [myid:5] - INFO [main:QuorumPeer@1158] - tickTime set to 2000 2020-03-23 11:36:58,861 [myid:5] - INFO [main:QuorumPeer@1204] - initLimit set to 10 2020-03-23 11:36:58,861 [myid:5] - INFO [main:QuorumPeer@1178] - minSessionTimeout set to -1 2020-03-23 11:36:58,862 [myid:5] - INFO [main:QuorumPeer@1189] - maxSessionTimeout set to -1 2020-03-23 11:36:58,871 [myid:5] - INFO [main:QuorumPeer@1467] - QuorumPeer communication is not secured! 2020-03-23 11:36:58,871 [myid:5] - INFO [main:QuorumPeer@1496] - quorum.cnxn.threads.size set to 20 2020-03-23 11:36:58,872 [myid:5] - INFO [main:FileSnap@86] - Reading snapshot /data/zookeeper/data/version-2/snapshot.b91d0000003c 2020-03-23 11:36:59,290 [myid:5] - ERROR [main:QuorumPeer@692] - Unable to load database on diskjava.io.IOException: The accepted epoch, ba86 is less than the current epoch, ba87 at org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:689) at org.apache.zookeeper.server.quorum.QuorumPeer.start(QuorumPeer.java:635) at org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:170) at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:114) at org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:81) 2020-03-23 11:36:59,292 [myid:5] - ERROR [main:QuorumPeerMain@92] - Unexpected exception, exiting abnormally java.lang.RuntimeException: Unable to run quorum server at org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:693) at org.apache.zookeeper.server.quorum.QuorumPeer.start(QuorumPeer.java:635) at org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:170) at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:114) at org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:81) Caused by: java.io.IOException: The accepted epoch, ba86 is less than the current epoch, ba87 at org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:689) ... 4 more
日志中写着,正在读取zk的快照,然后就报错了,无法载入磁盘上的数据库,那么!我就把快照删了
snapshot.b91d0000003c,让其自己重新生成快照文件,完事了。
2020-03-23 11:36:58,872 [myid:5] - INFO [main:FileSnap@86] - Reading snapshot /data/zookeeper/data/version-2/snapshot.b91d0000003c 2020-03-23 11:36:59,290 [myid:5] - ERROR [main:QuorumPeer@692] - Unable to load database on disk
酸爽
[root@ZYC3-AQGK-LJCL-SRV05 deployer]# systemctl status zookeeper ● zookeeper.service - ZooKeeper Service Loaded: loaded (/etc/systemd/system/zookeeper.service; enabled; vendor preset: disabled) Active: active (running) since Mon 2020-03-23 12:12:08 CST; 5min ago Docs: http://zookeeper.apache.org Process: 25348 ExecStop=/opt/zookeeper/zookeeper-prod/bin/zkServer.sh stop /opt/zookeeper/zookeeper-prod/conf/zoo.cfg (code=exited, status=0/SUCCESS) Process: 25658 ExecStart=/opt/zookeeper/zookeeper-prod/bin/zkServer.sh start /opt/zookeeper/zookeeper-prod/conf/zoo.cfg (code=exited, status=0/SUCCESS) Main PID: 25667 (java) CGroup: /system.slice/zookeeper.service └─25667 java -Dzookeeper.log.dir=. -Dzookeeper.root.logger=INFO,CONSOLE -cp /opt/zookeeper/zookeeper-prod/bin/../build/classes:/opt/zookeeper/zookeeper-prod/bin/../build/lib/*.jar:/opt/zookeeper/zoo... Mar 23 12:12:07 ZYC3-AQGK-LJCL-SRV05 systemd[1]: Starting ZooKeeper Service... Mar 23 12:12:07 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[25658]: ZooKeeper JMX enabled by default Mar 23 12:12:07 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[25658]: Using config: /opt/zookeeper/zookeeper-prod/conf/zoo.cfg Mar 23 12:12:08 ZYC3-AQGK-LJCL-SRV05 zkServer.sh[25658]: Starting zookeeper ... STARTED Mar 23 12:12:08 ZYC3-AQGK-LJCL-SRV05 systemd[1]: Started ZooKeeper Service.
因为zk每次运行的时候都会有个一快照文件,这个是状态恢复用的,由于这台主机之前磁盘满了,导入zk无法及时写入消息,之后我们将设备进行重启,应该就是这个时候,快照文件写入失败导致的。不过这个也不是万能解法,也是要具体问题具体分析,因为在集群中,把快照文件删了,后续想恢复数据库状态就难了,不过幸亏我们的zk是6节点的,另外五个节点正常,所以这么操作是允许的。
至此收工:)
相关文章推荐
- SQL Server由于登录失败而无法启动服务的解决方法
- SQLServer2000发生错误1069(由于登陆失败而无法启动服务)的解决方案[zz]
- sshd由于登录失败而无法启动--cygwin安装过程
- serve-u 错误1069 由于登陆失败而无法启动服务
- SQLServer2000发生错误1069(由于登陆失败而无法启动服务)的解决方案
- sql server2000由于登录失败而无法启动服务解决(错误1069)
- SQL 4000 Server 服务由于登录失败而无法启动
- 安装 oracle 11g 发行版 出现错误:由于以下错误,Enterprise Manager配置失败,启动Database Control时出错
- [SQL 2000]发生错误1069:由于登录失败而无法启动服务
- zookeeper无法启动"Unable to load database on disk"
- 1069错误(由于登录失败而无法启动服务)解决方法
- SQL Server 2008 报错 1069错误(由于登录失败而无法启动服务)解决方法
- SQL Server 2000启动1069错误(由于登录失败而无法启动服务)解决方法
- mssql1069错误(由于登录失败而无法启动服务)解决方法
- SQL server无法启动服务,提示“错误1069: 由于登录失败而无法启动服务”
- SQLServer2000发生错误1069(由于登陆失败而无法启动服务)的解决方案
- SQL Server 2005 服务启动失败 1069错误(由于登录失败而无法启动服务)解决方法
- 【SAP BO】【DI】DataService 服务无法启动。错误1069:由于登录失败而无法启动服务
- 解决错误1069:由于登录失败而无法启动服务
- 1069错误(由于登录失败而无法启动服务)解决方法