본문 바로가기

Infra

Zookeeper 불량문제

더보기
더보기
root@controller1-zookeeper-container-5be4bd4c:/var/lib/zookeeper/version-2# /opt/zookeeper/bin/zkServer.sh --config /etc/zookeeper start-foreground
/usr/bin/java
ZooKeeper JMX enabled by default
Using config: /etc/zookeeper/zoo.cfg
2024-07-11 01:15:26,546 [myid:] - INFO  [main:QuorumPeerConfig@174] - Reading configuration from: /etc/zookeeper/zoo.cfg
2024-07-11 01:15:26,559 [myid:] - INFO  [main:QuorumPeerConfig@444] - clientPortAddress is 0.0.0.0:2181
2024-07-11 01:15:26,560 [myid:] - INFO  [main:QuorumPeerConfig@457] - secureClientPortAddress is 0.0.0.0:2281
2024-07-11 01:15:26,566 [myid:] - INFO  [main:X509Util@77] - Setting -D jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated TLS renegotiation
2024-07-11 01:15:26,567 [myid:] - INFO  [main:QuorumPeerConfig@464] - observerMasterPort is not set
2024-07-11 01:15:26,567 [myid:] - INFO  [main:QuorumPeerConfig@481] - metricsProvider.className is org.apache.zookeeper.metrics.prometheus.PrometheusMetricsProvider
2024-07-11 01:15:26,585 [myid:1] - INFO  [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3
2024-07-11 01:15:26,585 [myid:1] - INFO  [main:DatadirCleanupManager@79] - autopurge.purgeInterval set to 1
2024-07-11 01:15:26,589 [myid:1] - INFO  [main:ManagedUtil@46] - Log4j 1.2 jmx support not found; jmx disabled.
2024-07-11 01:15:26,589 [myid:1] - INFO  [main:QuorumPeerMain@152] - Starting quorum peer, myid=1
2024-07-11 01:15:26,594 [myid:1] - INFO  [PurgeTask:DatadirCleanupManager$PurgeTask@139] - Purge task started.
2024-07-11 01:15:26,674 [myid:1] - INFO  [PurgeTask:FileTxnSnapLog@124] - zookeeper.snapshot.trust.empty : false
2024-07-11 01:15:26,735 [myid:1] - INFO  [PurgeTask:DatadirCleanupManager$PurgeTask@145] - Purge task completed.
2024-07-11 01:15:26,739 [myid:1] - INFO  [main:PrometheusMetricsProvider@74] - Initializing metrics, configuration: {}
2024-07-11 01:15:26,740 [myid:1] - INFO  [main:PrometheusMetricsProvider@82] - Starting /metrics HTTP endpoint at port 7000 exportJvmInfo: true
2024-07-11 01:15:26,811 [myid:1] - INFO  [main:Log@170] - Logging initialized @1145ms to org.eclipse.jetty.util.log.Slf4jLog
2024-07-11 01:15:26,993 [myid:1] - INFO  [main:Server@375] - jetty-9.4.43.v20210629; built: 2021-06-30T11:07:22.254Z; git: 526006ecfa3af7f1a27ef3a288e2bef7ea9dd7e8; jvm 11.0.20.1+1-post-Ubuntu-0ubuntu120.04
2024-07-11 01:15:27,083 [myid:1] - INFO  [main:ContextHandler@915] - Started o.e.j.s.ServletContextHandler@24aed80c{/,null,AVAILABLE}
2024-07-11 01:15:27,137 [myid:1] - INFO  [main:AbstractConnector@331] - Started ServerConnector@35ef1869{HTTP/1.1, (http/1.1)}{0.0.0.0:7000}
2024-07-11 01:15:27,138 [myid:1] - INFO  [main:Server@415] - Started @1472ms
2024-07-11 01:15:27,164 [myid:1] - INFO  [main:ServerMetrics@62] - ServerMetrics initialized with provider org.apache.zookeeper.metrics.prometheus.PrometheusMetricsProvider@3e96bacf
2024-07-11 01:15:27,200 [myid:1] - INFO  [main:DigestAuthenticationProvider@47] - ACL digest algorithm is: SHA1
2024-07-11 01:15:27,200 [myid:1] - INFO  [main:DigestAuthenticationProvider@61] - zookeeper.DigestAuthenticationProvider.enabled = true
2024-07-11 01:15:27,696 [myid:1] - INFO  [main:NettyServerCnxnFactory@519] - zookeeper.client.portUnification=false
2024-07-11 01:15:27,696 [myid:1] - INFO  [main:NettyServerCnxnFactory@531] - zookeeper.netty.advancedFlowControl.enabled = false
2024-07-11 01:15:27,697 [myid:1] - INFO  [main:NettyServerCnxnFactory@107] - handshakeThrottlingEnabled = false, zookeeper.netty.server.outstandingHandshake.limit = -1
2024-07-11 01:15:27,792 [myid:1] - INFO  [main:ServerCnxnFactory@169] - Using org.apache.zookeeper.server.NettyServerCnxnFactory as server connection factory
2024-07-11 01:15:27,794 [myid:1] - WARN  [main:ServerCnxnFactory@309] - maxCnxns is not configured, using default value 0.
2024-07-11 01:15:27,794 [myid:1] - INFO  [main:NettyServerCnxnFactory@618] - configure org.apache.zookeeper.server.NettyServerCnxnFactory@41005828 secure: false on addr 0.0.0.0/0.0.0.0:2181
2024-07-11 01:15:27,795 [myid:1] - INFO  [main:NettyServerCnxnFactory@519] - zookeeper.client.portUnification=false
2024-07-11 01:15:27,795 [myid:1] - INFO  [main:NettyServerCnxnFactory@531] - zookeeper.netty.advancedFlowControl.enabled = false
2024-07-11 01:15:27,795 [myid:1] - INFO  [main:NettyServerCnxnFactory@107] - handshakeThrottlingEnabled = false, zookeeper.netty.server.outstandingHandshake.limit = -1
2024-07-11 01:15:27,858 [myid:1] - INFO  [main:ServerCnxnFactory@169] - Using org.apache.zookeeper.server.NettyServerCnxnFactory as server connection factory
2024-07-11 01:15:27,858 [myid:1] - WARN  [main:ServerCnxnFactory@309] - maxCnxns is not configured, using default value 0.
2024-07-11 01:15:27,858 [myid:1] - INFO  [main:NettyServerCnxnFactory@618] - configure org.apache.zookeeper.server.NettyServerCnxnFactory@4397ad89 secure: true on addr 0.0.0.0/0.0.0.0:2281
2024-07-11 01:15:27,877 [myid:1] - INFO  [main:QuorumPeer@797] - zookeeper.quorumCnxnTimeoutMs=-1
2024-07-11 01:15:27,904 [myid:1] - WARN  [main:ContextHandler@1656] - o.e.j.s.ServletContextHandler@1efe439d{/,null,STOPPED} contextPath ends with /*
2024-07-11 01:15:27,904 [myid:1] - WARN  [main:ContextHandler@1667] - Empty contextPath
2024-07-11 01:15:27,921 [myid:1] - INFO  [main:FileTxnSnapLog@124] - zookeeper.snapshot.trust.empty : false
2024-07-11 01:15:27,929 [myid:1] - INFO  [main:QuorumPeer@1747] - Local sessions disabled
2024-07-11 01:15:27,929 [myid:1] - INFO  [main:QuorumPeer@1758] - Local session upgrading disabled
2024-07-11 01:15:27,929 [myid:1] - INFO  [main:QuorumPeer@1725] - tickTime set to 2000
2024-07-11 01:15:27,929 [myid:1] - INFO  [main:QuorumPeer@1769] - minSessionTimeout set to 4000
2024-07-11 01:15:27,930 [myid:1] - INFO  [main:QuorumPeer@1780] - maxSessionTimeout set to 40000
2024-07-11 01:15:27,930 [myid:1] - INFO  [main:QuorumPeer@1805] - initLimit set to 10
2024-07-11 01:15:27,930 [myid:1] - INFO  [main:QuorumPeer@1992] - syncLimit set to 5
2024-07-11 01:15:27,930 [myid:1] - INFO  [main:QuorumPeer@2007] - connectToLearnerMasterLimit set to 0
2024-07-11 01:15:27,946 [myid:1] - INFO  [main:ZookeeperBanner@42] -
2024-07-11 01:15:27,946 [myid:1] - INFO  [main:ZookeeperBanner@42] -   ______                  _
2024-07-11 01:15:27,947 [myid:1] - INFO  [main:ZookeeperBanner@42] -  |___  /                 | |
2024-07-11 01:15:27,947 [myid:1] - INFO  [main:ZookeeperBanner@42] -     / /    ___     ___   | | __   ___    ___   _ __     ___   _ __
2024-07-11 01:15:27,947 [myid:1] - INFO  [main:ZookeeperBanner@42] -    / /    / _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
2024-07-11 01:15:27,947 [myid:1] - INFO  [main:ZookeeperBanner@42] -   / /__  | (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |
2024-07-11 01:15:27,947 [myid:1] - INFO  [main:ZookeeperBanner@42] -  /_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
2024-07-11 01:15:27,947 [myid:1] - INFO  [main:ZookeeperBanner@42] -                                               | |
2024-07-11 01:15:27,947 [myid:1] - INFO  [main:ZookeeperBanner@42] -                                               |_|
2024-07-11 01:15:27,947 [myid:1] - INFO  [main:ZookeeperBanner@42] -
2024-07-11 01:15:27,961 [myid:1] - INFO  [main:Environment@98] - Server environment:zookeeper.version=3.7.1-a2fb57c55f8e59cdd76c34b357ad5181df1258d5, built on 2022-05-07 06:45 UTC
2024-07-11 01:15:27,961 [myid:1] - INFO  [main:Environment@98] - Server environment:host.name=controller1-zookeeper-container-5be4bd4c.openstack.local
2024-07-11 01:15:27,961 [myid:1] - INFO  [main:Environment@98] - Server environment:java.version=11.0.20.1
2024-07-11 01:15:27,961 [myid:1] - INFO  [main:Environment@98] - Server environment:java.vendor=Ubuntu
2024-07-11 01:15:27,961 [myid:1] - INFO  [main:Environment@98] - Server environment:java.home=/usr/lib/jvm/java-11-openjdk-amd64
2024-07-11 01:15:27,962 [myid:1] - INFO  [main:Environment@98] - Server environment:java.class.path=/opt/zookeeper/bin/../zookeeper-server/target/classes:/opt/zookeeper/bin/../build/classes:/opt/zookeeper/bin/../zookeeper-server/target/lib/*.jar:/opt/zookeeper/bin/../build/lib/*.jar:/opt/zookeeper/bin/../lib/zookeeper-prometheus-metrics-3.7.1.jar:/opt/zookeeper/bin/../lib/zookeeper-jute-3.7.1.jar:/opt/zookeeper/bin/../lib/zookeeper-3.7.1.jar:/opt/zookeeper/bin/../lib/snappy-java-1.1.7.7.jar:/opt/zookeeper/bin/../lib/slf4j-reload4j-1.7.35.jar:/opt/zookeeper/bin/../lib/slf4j-api-1.7.35.jar:/opt/zookeeper/bin/../lib/simpleclient_servlet-0.9.0.jar:/opt/zookeeper/bin/../lib/simpleclient_hotspot-0.9.0.jar:/opt/zookeeper/bin/../lib/simpleclient_common-0.9.0.jar:/opt/zookeeper/bin/../lib/simpleclient-0.9.0.jar:/opt/zookeeper/bin/../lib/reload4j-1.2.19.jar:/opt/zookeeper/bin/../lib/netty-transport-native-unix-common-4.1.76.Final.jar:/opt/zookeeper/bin/../lib/netty-transport-native-epoll-4.1.76.Final.jar:/opt/zookeeper/bin/../lib/netty-transport-classes-epoll-4.1.76.Final.jar:/opt/zookeeper/bin/../lib/netty-transport-4.1.76.Final.jar:/opt/zookeeper/bin/../lib/netty-resolver-4.1.76.Final.jar:/opt/zookeeper/bin/../lib/netty-handler-4.1.76.Final.jar:/opt/zookeeper/bin/../lib/netty-common-4.1.76.Final.jar:/opt/zookeeper/bin/../lib/netty-codec-4.1.76.Final.jar:/opt/zookeeper/bin/../lib/netty-buffer-4.1.76.Final.jar:/opt/zookeeper/bin/../lib/metrics-core-4.1.12.1.jar:/opt/zookeeper/bin/../lib/jline-2.14.6.jar:/opt/zookeeper/bin/../lib/jetty-util-ajax-9.4.43.v20210629.jar:/opt/zookeeper/bin/../lib/jetty-util-9.4.43.v20210629.jar:/opt/zookeeper/bin/../lib/jetty-servlet-9.4.43.v20210629.jar:/opt/zookeeper/bin/../lib/jetty-server-9.4.43.v20210629.jar:/opt/zookeeper/bin/../lib/jetty-security-9.4.43.v20210629.jar:/opt/zookeeper/bin/../lib/jetty-io-9.4.43.v20210629.jar:/opt/zookeeper/bin/../lib/jetty-http-9.4.43.v20210629.jar:/opt/zookeeper/bin/../lib/javax.servlet-api-3.1.0.jar:/opt/zookeeper/bin/../lib/jackson-databind-2.13.2.1.jar:/opt/zookeeper/bin/../lib/jackson-core-2.13.2.jar:/opt/zookeeper/bin/../lib/jackson-annotations-2.13.2.jar:/opt/zookeeper/bin/../lib/commons-cli-1.4.jar:/opt/zookeeper/bin/../lib/audience-annotations-0.12.0.jar:/opt/zookeeper/bin/../zookeeper-*.jar:/opt/zookeeper/bin/../zookeeper-server/src/main/resources/lib/*.jar:/etc/zookeeper:
2024-07-11 01:15:27,962 [myid:1] - INFO  [main:Environment@98] - Server environment:java.library.path=/usr/java/packages/lib:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
2024-07-11 01:15:27,962 [myid:1] - INFO  [main:Environment@98] - Server environment:java.io.tmpdir=/tmp
2024-07-11 01:15:27,962 [myid:1] - INFO  [main:Environment@98] - Server environment:java.compiler=<NA>
2024-07-11 01:15:27,962 [myid:1] - INFO  [main:Environment@98] - Server environment:os.name=Linux
2024-07-11 01:15:27,962 [myid:1] - INFO  [main:Environment@98] - Server environment:os.arch=amd64
2024-07-11 01:15:27,962 [myid:1] - INFO  [main:Environment@98] - Server environment:os.version=5.4.0-187-generic
2024-07-11 01:15:27,963 [myid:1] - INFO  [main:Environment@98] - Server environment:user.name=root
2024-07-11 01:15:27,963 [myid:1] - INFO  [main:Environment@98] - Server environment:user.home=/root
2024-07-11 01:15:27,963 [myid:1] - INFO  [main:Environment@98] - Server environment:user.dir=/var/lib/zookeeper/version-2
2024-07-11 01:15:27,963 [myid:1] - INFO  [main:Environment@98] - Server environment:os.memory.free=955MB
2024-07-11 01:15:27,963 [myid:1] - INFO  [main:Environment@98] - Server environment:os.memory.max=1000MB
2024-07-11 01:15:27,963 [myid:1] - INFO  [main:Environment@98] - Server environment:os.memory.total=1000MB
2024-07-11 01:15:27,963 [myid:1] - INFO  [main:ZooKeeperServer@138] - zookeeper.enableEagerACLCheck = false
2024-07-11 01:15:27,964 [myid:1] - INFO  [main:ZooKeeperServer@151] - zookeeper.digest.enabled = true
2024-07-11 01:15:27,964 [myid:1] - INFO  [main:ZooKeeperServer@155] - zookeeper.closeSessionTxn.enabled = true
2024-07-11 01:15:27,964 [myid:1] - INFO  [main:ZooKeeperServer@1505] - zookeeper.flushDelay=0
2024-07-11 01:15:27,964 [myid:1] - INFO  [main:ZooKeeperServer@1514] - zookeeper.maxWriteQueuePollTime=0
2024-07-11 01:15:27,964 [myid:1] - INFO  [main:ZooKeeperServer@1523] - zookeeper.maxBatchSize=1000
2024-07-11 01:15:27,964 [myid:1] - INFO  [main:ZooKeeperServer@260] - zookeeper.intBufferStartingSizeBytes = 1024
2024-07-11 01:15:27,983 [myid:1] - INFO  [main:WatchManagerFactory@42] - Using org.apache.zookeeper.server.watch.WatchManager as watch manager
2024-07-11 01:15:27,984 [myid:1] - INFO  [main:WatchManagerFactory@42] - Using org.apache.zookeeper.server.watch.WatchManager as watch manager
2024-07-11 01:15:27,988 [myid:1] - INFO  [main:ZKDatabase@133] - zookeeper.snapshotSizeFactor = 0.33
2024-07-11 01:15:27,989 [myid:1] - INFO  [main:ZKDatabase@153] - zookeeper.commitLogCount=500
2024-07-11 01:15:28,004 [myid:1] - INFO  [main:QuorumPeer@2069] - Using TLS encrypted quorum communication
2024-07-11 01:15:28,005 [myid:1] - INFO  [main:QuorumPeer@2077] - Port unification disabled
2024-07-11 01:15:28,005 [myid:1] - INFO  [main:QuorumPeer@180] - multiAddress.enabled set to false
2024-07-11 01:15:28,005 [myid:1] - INFO  [main:QuorumPeer@205] - multiAddress.reachabilityCheckEnabled set to true
2024-07-11 01:15:28,005 [myid:1] - INFO  [main:QuorumPeer@192] - multiAddress.reachabilityCheckTimeoutMs set to 1000
2024-07-11 01:15:28,005 [myid:1] - INFO  [main:QuorumPeer@2532] - QuorumPeer communication is not secured! (SASL auth disabled)
2024-07-11 01:15:28,005 [myid:1] - INFO  [main:QuorumPeer@2557] - quorum.cnxn.threads.size set to 20
2024-07-11 01:15:28,033 [myid:1] - WARN  [main:FileTxnLog@366] - Unexpected exception
java.io.EOFException
        at java.base/java.io.DataInputStream.readInt(DataInputStream.java:397)
        at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:96)
        at org.apache.zookeeper.server.persistence.FileHeader.deserialize(FileHeader.java:67)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.inStreamCreated(FileTxnLog.java:706)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.createInputArchive(FileTxnLog.java:724)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.goToNextLog(FileTxnLog.java:692)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.init(FileTxnLog.java:668)
        at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.<init>(FileTxnLog.java:627)
        at org.apache.zookeeper.server.persistence.FileTxnLog.read(FileTxnLog.java:447)
        at org.apache.zookeeper.server.persistence.FileTxnLog.read(FileTxnLog.java:434)
        at org.apache.zookeeper.server.persistence.FileTxnLog.getLastLoggedZxid(FileTxnLog.java:357)
        at org.apache.zookeeper.server.persistence.FileTxnSnapLog.restore(FileTxnSnapLog.java:286)
        at org.apache.zookeeper.server.ZKDatabase.loadDataBase(ZKDatabase.java:286)
        at org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:1145)
        at org.apache.zookeeper.server.quorum.QuorumPeer.start(QuorumPeer.java:1131)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:229)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:137)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:91)
2024-07-11 01:15:28,054 [myid:1] - ERROR [main:QuorumPeer@1199] - Unable to load database on disk
java.io.IOException: No snapshot found, but there are log entries. Something is broken!
        at org.apache.zookeeper.server.persistence.FileTxnSnapLog.restore(FileTxnSnapLog.java:290)
        at org.apache.zookeeper.server.ZKDatabase.loadDataBase(ZKDatabase.java:286)
        at org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:1145)
        at org.apache.zookeeper.server.quorum.QuorumPeer.start(QuorumPeer.java:1131)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:229)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:137)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:91)
2024-07-11 01:15:28,181 [myid:1] - INFO  [main:AbstractConnector@381] - Stopped ServerConnector@35ef1869{HTTP/1.1, (http/1.1)}{0.0.0.0:7000}
2024-07-11 01:15:28,185 [myid:1] - INFO  [main:ContextHandler@1153] - Stopped o.e.j.s.ServletContextHandler@24aed80c{/,null,STOPPED}
2024-07-11 01:15:28,194 [myid:1] - ERROR [main:QuorumPeerMain@114] - Unexpected exception, exiting abnormally
java.lang.RuntimeException: Unable to run quorum server
        at org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:1200)
        at org.apache.zookeeper.server.quorum.QuorumPeer.start(QuorumPeer.java:1131)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:229)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:137)
        at org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:91)
Caused by: java.io.IOException: No snapshot found, but there are log entries. Something is broken!
        at org.apache.zookeeper.server.persistence.FileTxnSnapLog.restore(FileTxnSnapLog.java:290)
        at org.apache.zookeeper.server.ZKDatabase.loadDataBase(ZKDatabase.java:286)
        at org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:1145)
        ... 4 more
2024-07-11 01:15:28,196 [myid:1] - INFO  [main:ZKAuditProvider@42] - ZooKeeper audit is disabled.
2024-07-11 01:15:28,199 [myid:1] - ERROR [main:ServiceUtils@48] - Exiting JVM with code 1

 

위와 같은 Unable to load database on disk 에러 발생

Zookeeper 노드가 죽었다가 살아나면서 snapshot 정보와 log 정보가 달라져서 생긴 문제로 판단

초기화 하는 방법으로 해결

/var/lib/zookeeper/version-2/ 에 있는 파일을 backup

/var/lib/zookeeper/log/version-2/ 에 있는 파일을 backup

zookeeper 재시작

 

zookeeper가 죽을 경우 cinder가 불량이 되는 문제가 발생

cinder가 불량이 될 경우 horizon에서 nova 정보를 못 가져오는 문제 발생

'Infra' 카테고리의 다른 글

SR-IOV와 VF 개수 상관 관계  (0) 2024.06.26
Mellanox 설치  (0) 2024.05.25
Journal Log 용량 제한  (0) 2024.05.24
Squid proxy 폐쇄망 연결  (0) 2024.05.23
sFlow Dashboard  (0) 2024.05.23