search

apache / bookkeeper

Apache BookKeeper - a scalable, fault tolerant and low latency storage service optimized for append-only workloads
https://bookkeeper.apache.org/
Apache License 2.0
1.91k stars 904 forks source link

Bookkeeper write Metadata to zookeeper failed #2340

Closed coolbeevip closed 7 months ago

coolbeevip commented 4 years ago

I build bookkeeper docker image locally based on master branch.

This is my docker-compose.yml

version: '3.2'
services:
  zookeeper:
    image: zookeeper
    hostname: zookeeper
    container_name: zookeeper
    networks:
      - my-net
    ports:
      - 2181:2181
    environment:
      - ALLOW_ANONYMOUS_LOGIN=yes
  bookie:
    image: apache/bookkeeper
    hostname: bookie
    container_name: bookie
    networks:
      - my-net
    ports:
      - 3181:3181
    environment:
      - JAVA_HOME=/usr/lib/jvm/jre-1.8.0
      - BK_zkServers=zookeeper:2181
      - BK_zkLedgersRootPath=/bookkeeper/ledgers
      - BK_bookiePort=3181
      - BK_DATA_DIR=/bookkeeper/data
networks:
  my-net:
    external: true

The log error is as follows：

(base) bogon:mydocker zhanglei$ docker-compose -f bookkeeper.yml up
Creating zookeeper ... done
Creating bookie    ... done
Attaching to bookie, zookeeper
bookie       | Environment Vars for bookie:
bookie       |
bookie       |   [metadata service]
bookie       |   BK_zkServers is zookeeper:2181
bookie       |   BK_CLUSTER_ROOT_PATH is
bookie       |   BK_metadataServiceUri is zk://zookeeper:2181/bookkeeper/ledgers
bookie       |
bookie       |   [bookie]
bookie       |   BK_bookiePort bookie service port is 3181
bookie       |   BK_DATA_DIR is /bookkeeper/data
bookie       |   BK_journalDirectory is /bookkeeper/data/journal
bookie       |   BK_ledgerDirectories are /bookkeeper/data/ledgers
bookie       |   BK_indexDirectories are /bookkeeper/data/ledgers
bookie       |
bookie       |   [bookie http]
bookie       |   BK_httpServerEnabled is true
bookie       |   BK_httpServerPort is
bookie       |
bookie       |   [dlog]
bookie       |   BK_dlogRootPath is /distributedlog
bookie       |
bookie       |   [stream storage]
bookie       |   BK_STREAM_STORAGE_ROOT_PATH is /stream
bookie       |   BK_NUM_STORAGE_CONTAINERS is 32
bookie       |   BOOKIE_GRPC_PORT is
bookie       | conf files:
bookie       | ['/opt/bookkeeper/conf/bk_cli_env.sh', '/opt/bookkeeper/conf/standalone.conf', '/opt/bookkeeper/conf/bkenv.sh', '/opt/bookkeeper/conf/log4j.properties', '/opt/bookkeeper/conf/bk_server.conf', '/opt/bookkeeper/conf/zookeeper.conf', '/opt/bookkeeper/conf/log4j.cli.properties', '/opt/bookkeeper/conf/jaas_example.conf', '/opt/bookkeeper/conf/nettyenv.sh', '/opt/bookkeeper/conf/log4j.shell.properties', '/opt/bookkeeper/conf/zookeeper.conf.dynamic']
bookie       | [/opt/bookkeeper/conf/bk_server.conf] Applying config bookiePort = 3181
bookie       | [/opt/bookkeeper/conf/bk_server.conf] Applying config httpServerEnabled = true
bookie       | [/opt/bookkeeper/conf/bk_server.conf] Applying config httpServerPort =
bookie       | [/opt/bookkeeper/conf/bk_server.conf] Applying config indexDirectories = /bookkeeper/data/ledgers
bookie       | [/opt/bookkeeper/conf/bk_server.conf] Applying config journalDirectory = /bookkeeper/data/journal
bookie       | [/opt/bookkeeper/conf/bk_server.conf] Applying config ledgerDirectories = /bookkeeper/data/ledgers
bookie       | [/opt/bookkeeper/conf/bk_server.conf] Applying config metadataServiceUri = zk://zookeeper:2181/bookkeeper/ledgers
bookie       | [/opt/bookkeeper/conf/bk_server.conf] Applying config zkLedgersRootPath = /bookkeeper/ledgers
bookie       | [/opt/bookkeeper/conf/bk_server.conf] Applying config zkServers = zookeeper:2181
bookie       | Created bookie dirs :
bookie       |   journal = /bookkeeper/data/journal
bookie       |   ledger = /bookkeeper/data/ledgers
bookie       |   index = /bookkeeper/data/ledgers
bookie       | wait for zookeeper
zookeeper    | ZooKeeper JMX enabled by default
zookeeper    | Using config: /conf/zoo.cfg
zookeeper    | 2020-05-21 09:48:47,073 [myid:] - INFO  [main:QuorumPeerConfig@133] - Reading configuration from: /conf/zoo.cfg
zookeeper    | 2020-05-21 09:48:47,086 [myid:] - INFO  [main:QuorumPeerConfig@375] - clientPort is not set
zookeeper    | 2020-05-21 09:48:47,086 [myid:] - INFO  [main:QuorumPeerConfig@389] - secureClientPort is not set
zookeeper    | 2020-05-21 09:48:47,100 [myid:] - ERROR [main:QuorumPeerConfig@645] - Invalid configuration, only one server specified (ignoring)
zookeeper    | 2020-05-21 09:48:47,111 [myid:1] - INFO  [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3
zookeeper    | 2020-05-21 09:48:47,112 [myid:1] - INFO  [main:DatadirCleanupManager@79] - autopurge.purgeInterval set to 0
zookeeper    | 2020-05-21 09:48:47,112 [myid:1] - INFO  [main:DatadirCleanupManager@101] - Purge task is not scheduled.
zookeeper    | 2020-05-21 09:48:47,112 [myid:1] - WARN  [main:QuorumPeerMain@125] - Either no config or no quorum defined in config, running  in standalone mode
zookeeper    | 2020-05-21 09:48:47,115 [myid:1] - INFO  [main:ManagedUtil@46] - Log4j found with jmx enabled.
zookeeper    | 2020-05-21 09:48:47,141 [myid:1] - INFO  [main:QuorumPeerConfig@133] - Reading configuration from: /conf/zoo.cfg
zookeeper    | 2020-05-21 09:48:47,142 [myid:1] - INFO  [main:QuorumPeerConfig@375] - clientPort is not set
zookeeper    | 2020-05-21 09:48:47,142 [myid:1] - INFO  [main:QuorumPeerConfig@389] - secureClientPort is not set
zookeeper    | 2020-05-21 09:48:47,143 [myid:1] - ERROR [main:QuorumPeerConfig@645] - Invalid configuration, only one server specified (ignoring)
zookeeper    | 2020-05-21 09:48:47,143 [myid:1] - INFO  [main:ZooKeeperServerMain@117] - Starting server
zookeeper    | 2020-05-21 09:48:47,149 [myid:1] - INFO  [main:FileTxnSnapLog@103] - zookeeper.snapshot.trust.empty : false
zookeeper    | 2020-05-21 09:48:47,186 [myid:1] - INFO  [main:Environment@109] - Server environment:zookeeper.version=3.5.6-c11b7e26bc554b8523dc929761dd28808913f091, built on 10/08/2019 20:18 GMT
zookeeper    | 2020-05-21 09:48:47,188 [myid:1] - INFO  [main:Environment@109] - Server environment:host.name=zookeeper
zookeeper    | 2020-05-21 09:48:47,188 [myid:1] - INFO  [main:Environment@109] - Server environment:java.version=1.8.0_232
zookeeper    | 2020-05-21 09:48:47,188 [myid:1] - INFO  [main:Environment@109] - Server environment:java.vendor=Oracle Corporation
zookeeper    | 2020-05-21 09:48:47,189 [myid:1] - INFO  [main:Environment@109] - Server environment:java.home=/usr/local/openjdk-8
zookeeper    | 2020-05-21 09:48:47,189 [myid:1] - INFO  [main:Environment@109] - Server environment:java.class.path=/apache-zookeeper-3.5.6-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.5.6-bin/bin/../build/classes:/apache-zookeeper-3.5.6-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.5.6-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/zookeeper-jute-3.5.6.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/zookeeper-3.5.6.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/netty-transport-native-unix-common-4.1.42.Final.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/netty-transport-native-epoll-4.1.42.Final.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/netty-transport-4.1.42.Final.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/netty-resolver-4.1.42.Final.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/netty-handler-4.1.42.Final.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/netty-common-4.1.42.Final.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/netty-codec-4.1.42.Final.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/netty-buffer-4.1.42.Final.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/jetty-util-9.4.17.v20190418.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/jetty-servlet-9.4.17.v20190418.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/jetty-server-9.4.17.v20190418.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/jetty-security-9.4.17.v20190418.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/jetty-io-9.4.17.v20190418.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/jetty-http-9.4.17.v20190418.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/jackson-databind-2.9.10.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/jackson-core-2.9.10.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/jackson-annotations-2.9.10.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.5.6-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.5.6-bin/bin/../zookeeper-*.jar:/apache-zookeeper-3.5.6-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
zookeeper    | 2020-05-21 09:48:47,190 [myid:1] - INFO  [main:Environment@109] - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
zookeeper    | 2020-05-21 09:48:47,190 [myid:1] - INFO  [main:Environment@109] - Server environment:java.io.tmpdir=/tmp
zookeeper    | 2020-05-21 09:48:47,190 [myid:1] - INFO  [main:Environment@109] - Server environment:java.compiler=<NA>
zookeeper    | 2020-05-21 09:48:47,190 [myid:1] - INFO  [main:Environment@109] - Server environment:os.name=Linux
zookeeper    | 2020-05-21 09:48:47,191 [myid:1] - INFO  [main:Environment@109] - Server environment:os.arch=amd64
zookeeper    | 2020-05-21 09:48:47,191 [myid:1] - INFO  [main:Environment@109] - Server environment:os.version=4.19.76-linuxkit
zookeeper    | 2020-05-21 09:48:47,191 [myid:1] - INFO  [main:Environment@109] - Server environment:user.name=zookeeper
zookeeper    | 2020-05-21 09:48:47,192 [myid:1] - INFO  [main:Environment@109] - Server environment:user.home=/home/zookeeper
zookeeper    | 2020-05-21 09:48:47,192 [myid:1] - INFO  [main:Environment@109] - Server environment:user.dir=/apache-zookeeper-3.5.6-bin
zookeeper    | 2020-05-21 09:48:47,192 [myid:1] - INFO  [main:Environment@109] - Server environment:os.memory.free=50MB
zookeeper    | 2020-05-21 09:48:47,192 [myid:1] - INFO  [main:Environment@109] - Server environment:os.memory.max=889MB
zookeeper    | 2020-05-21 09:48:47,192 [myid:1] - INFO  [main:Environment@109] - Server environment:os.memory.total=59MB
zookeeper    | 2020-05-21 09:48:47,198 [myid:1] - INFO  [main:ZooKeeperServer@938] - minSessionTimeout set to 4000
zookeeper    | 2020-05-21 09:48:47,198 [myid:1] - INFO  [main:ZooKeeperServer@947] - maxSessionTimeout set to 40000
zookeeper    | 2020-05-21 09:48:47,199 [myid:1] - INFO  [main:ZooKeeperServer@166] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /datalog/version-2 snapdir /data/version-2
zookeeper    | 2020-05-21 09:48:47,299 [myid:1] - INFO  [main:Log@193] - Logging initialized @1447ms to org.eclipse.jetty.util.log.Slf4jLog
zookeeper    | 2020-05-21 09:48:47,542 [myid:1] - WARN  [main:ContextHandler@1588] - o.e.j.s.ServletContextHandler@5649fd9b{/,null,UNAVAILABLE} contextPath ends with /*
zookeeper    | 2020-05-21 09:48:47,542 [myid:1] - WARN  [main:ContextHandler@1599] - Empty contextPath
zookeeper    | 2020-05-21 09:48:47,568 [myid:1] - INFO  [main:Server@370] - jetty-9.4.17.v20190418; built: 2019-04-18T19:45:35.259Z; git: aa1c656c315c011c01e7b21aabb04066635b9f67; jvm 1.8.0_232-b09
zookeeper    | 2020-05-21 09:48:47,687 [myid:1] - INFO  [main:DefaultSessionIdManager@365] - DefaultSessionIdManager workerName=node0
zookeeper    | 2020-05-21 09:48:47,688 [myid:1] - INFO  [main:DefaultSessionIdManager@370] - No SessionScavenger set, using defaults
zookeeper    | 2020-05-21 09:48:47,691 [myid:1] - INFO  [main:HouseKeeper@149] - node0 Scavenging every 660000ms
zookeeper    | 2020-05-21 09:48:47,724 [myid:1] - INFO  [main:ContextHandler@855] - Started o.e.j.s.ServletContextHandler@5649fd9b{/,null,AVAILABLE}
zookeeper    | 2020-05-21 09:48:47,736 [myid:1] - INFO  [main:AbstractConnector@292] - Started ServerConnector@4520ebad{HTTP/1.1,[http/1.1]}{0.0.0.0:8080}
zookeeper    | 2020-05-21 09:48:47,737 [myid:1] - INFO  [main:Server@410] - Started @1951ms
zookeeper    | 2020-05-21 09:48:47,737 [myid:1] - INFO  [main:JettyAdminServer@112] - Started AdminServer on address 0.0.0.0, port 8080 and command URL /commands
zookeeper    | 2020-05-21 09:48:47,751 [myid:1] - INFO  [main:ServerCnxnFactory@135] - Using org.apache.zookeeper.server.NIOServerCnxnFactory as server connection factory
zookeeper    | 2020-05-21 09:48:47,763 [myid:1] - INFO  [main:NIOServerCnxnFactory@673] - Configuring NIO connection handler with 10s sessionless connection timeout, 1 selector thread(s), 8 worker threads, and 64 kB direct buffers.
zookeeper    | 2020-05-21 09:48:47,766 [myid:1] - INFO  [main:NIOServerCnxnFactory@686] - binding to port /0.0.0.0:2181
zookeeper    | 2020-05-21 09:48:47,797 [myid:1] - INFO  [main:ZKDatabase@117] - zookeeper.snapshotSizeFactor = 0.33
zookeeper    | 2020-05-21 09:48:47,804 [myid:1] - INFO  [main:FileTxnSnapLog@384] - Snapshotting: 0x0 to /data/version-2/snapshot.0
zookeeper    | 2020-05-21 09:48:47,814 [myid:1] - INFO  [main:FileTxnSnapLog@384] - Snapshotting: 0x0 to /data/version-2/snapshot.0
zookeeper    | 2020-05-21 09:48:47,857 [myid:1] - INFO  [main:ContainerManager@64] - Using checkIntervalMs=60000 maxPerMinute=10000
zookeeper    | 2020-05-21 09:48:49,351 [myid:1] - INFO  [SyncThread:0:FileTxnLog@216] - Creating new log file: log.1
bookie       | zookeeper
zookeeper    | 2020-05-21 09:48:49,459 [myid:1] - WARN  [NIOWorkerThread-7:NIOServerCnxn@366] - Unable to read additional data from client sessionid 0x100098b513a0000, likely client has closed socket
bookie       | Path /bookkeeper/ledgers/available/readonly doesn't exist
zookeeper    | 2020-05-21 09:48:49,608 [myid:1] - WARN  [NIOWorkerThread-4:NIOServerCnxn@366] - Unable to read additional data from client sessionid 0x100098b513a0001, likely client has closed socket
bookie       | znodes do not exist in Zookeeper for Bookkeeper. Initializing a new Bookkeekeper cluster in Zookeeper.
zookeeper    | 2020-05-21 09:48:49,767 [myid:1] - WARN  [NIOWorkerThread-3:NIOServerCnxn@366] - Unable to read additional data from client sessionid 0x100098b513a0002, likely client has closed socket
bookie       | Exception in thread "main" java.util.concurrent.ExecutionException: KeeperErrorCode = NoNode
bookie       |  at org.apache.bookkeeper.meta.MetadataDrivers.runFunctionWithMetadataBookieDriver(MetadataDrivers.java:378)
bookie       |  at org.apache.bookkeeper.meta.MetadataDrivers.runFunctionWithRegistrationManager(MetadataDrivers.java:398)
bookie       |  at org.apache.bookkeeper.client.BookKeeperAdmin.initNewCluster(BookKeeperAdmin.java:1197)
bookie       |  at org.apache.bookkeeper.bookie.BookieShell$InitNewCluster.runCmd(BookieShell.java:368)
bookie       |  at org.apache.bookkeeper.bookie.BookieShell$MyCommand.runCmd(BookieShell.java:277)
bookie       |  at org.apache.bookkeeper.bookie.BookieShell.run(BookieShell.java:3081)
bookie       |  at org.apache.bookkeeper.bookie.BookieShell.main(BookieShell.java:3172)
bookie       | Caused by: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode
bookie       |  at org.apache.zookeeper.KeeperException.create(KeeperException.java:114)
bookie       |  at org.apache.zookeeper.ZooKeeper.multiInternal(ZooKeeper.java:1015)
bookie       |  at org.apache.zookeeper.ZooKeeper.multi(ZooKeeper.java:919)
bookie       |  at org.apache.bookkeeper.zookeeper.ZooKeeperClient.access$801(ZooKeeperClient.java:70)
bookie       |  at org.apache.bookkeeper.zookeeper.ZooKeeperClient$2.call(ZooKeeperClient.java:466)
bookie       |  at org.apache.bookkeeper.zookeeper.ZooKeeperClient$2.call(ZooKeeperClient.java:455)
bookie       |  at org.apache.bookkeeper.zookeeper.ZooWorker.syncCallWithRetries(ZooWorker.java:140)
bookie       |  at org.apache.bookkeeper.zookeeper.ZooKeeperClient.multi(ZooKeeperClient.java:455)
bookie       |  at org.apache.bookkeeper.discover.ZKRegistrationManager.initNewCluster(ZKRegistrationManager.java:453)
bookie       |  at org.apache.bookkeeper.client.BookKeeperAdmin.lambda$initNewCluster$3(BookKeeperAdmin.java:1199)
bookie       |  at org.apache.bookkeeper.meta.MetadataDrivers.lambda$runFunctionWithRegistrationManager$1(MetadataDrivers.java:398)
bookie       |  at org.apache.bookkeeper.meta.MetadataDrivers.runFunctionWithMetadataBookieDriver(MetadataDrivers.java:373)
bookie       |  ... 6 more
bookie       | initnewcluster operation failed. Please check the reason.
bookie       | Exit status of initnewcluster
bookie       | 0
bookie exited with code 0
zookeeper    | 2020-05-21 09:49:00,579 [myid:1] - INFO  [SessionTracker:ZooKeeperServer@398] - Expiring session 0x100098b513a0000, timeout of 10000ms exceeded
zookeeper    | 2020-05-21 09:49:00,580 [myid:1] - INFO  [SessionTracker:ZooKeeperServer@398] - Expiring session 0x100098b513a0001, timeout of 10000ms exceeded
zookeeper    | 2020-05-21 09:49:00,580 [myid:1] - INFO  [SessionTracker:ZooKeeperServer@398] - Expiring session 0x100098b513a0002, timeout of 10000ms exceeded
nicknezis commented 4 years ago

Is this related to #2219 ?

eolivelli commented 4 years ago

No. You are using /bookkeeper/ledgers

just change it to "/ledgers" or you have to add some zk-shell command to create /bookkeeper I thought we fixed that problem in 4.10, but may it is some different execution path