Got user-level KeeperException when processing
Asked Answered
M

1

27

I know this has been asked before, so please forgive me for asking again, but none of the solutions pointed to by that thread worked for me.

I'm trying to setup Kafka 0.10.20 following the docs. When I start ZooKeeper, I get the following logs:

$ bin/zookeeper-server-start.sh config/zookeeper.properties 
[2017-04-22 12:25:15,810] INFO Reading configuration from: config/zookeeper.properties (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2017-04-22 12:25:15,814] INFO autopurge.snapRetainCount set to 3 (org.apache.zookeeper.server.DatadirCleanupManager)
[2017-04-22 12:25:15,815] INFO autopurge.purgeInterval set to 0 (org.apache.zookeeper.server.DatadirCleanupManager)
[2017-04-22 12:25:15,815] INFO Purge task is not scheduled. (org.apache.zookeeper.server.DatadirCleanupManager)
[2017-04-22 12:25:15,815] WARN Either no config or no quorum defined in config, running  in standalone mode (org.apache.zookeeper.server.quorum.QuorumPeerMain)
[2017-04-22 12:25:15,837] INFO Reading configuration from: config/zookeeper.properties (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2017-04-22 12:25:15,837] INFO Starting server (org.apache.zookeeper.server.ZooKeeperServerMain)
[2017-04-22 12:25:15,855] INFO Server environment:zookeeper.version=3.4.9-1757313, built on 08/23/2016 06:50 GMT (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,855] INFO Server environment:host.name=10.0.0.4 (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,855] INFO Server environment:java.version=1.8.0_121 (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,856] INFO Server environment:java.vendor=Oracle Corporation (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,856] INFO Server environment:java.home=/usr/lib/jvm/java-8-oracle/jre (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,856] INFO Server environment:java.class.path=:/home/bbanner/kafka-1/bin/../libs/aopalliance-repackaged-2.5.0-b05.jar:/home/bbanner/kafka-1/bin/../libs/argparse4j-0.7.0.jar:/home/bbanner/kafka-1/bin/../libs/connect-api-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/connect-file-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/connect-json-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/connect-runtime-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/connect-transforms-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/guava-18.0.jar:/home/bbanner/kafka-1/bin/../libs/hk2-api-2.5.0-b05.jar:/home/bbanner/kafka-1/bin/../libs/hk2-locator-2.5.0-b05.jar:/home/bbanner/kafka-1/bin/../libs/hk2-utils-2.5.0-b05.jar:/home/bbanner/kafka-1/bin/../libs/jackson-annotations-2.8.0.jar:/home/bbanner/kafka-1/bin/../libs/jackson-annotations-2.8.5.jar:/home/bbanner/kafka-1/bin/../libs/jackson-core-2.8.5.jar:/home/bbanner/kafka-1/bin/../libs/jackson-databind-2.8.5.jar:/home/bbanner/kafka-1/bin/../libs/jackson-jaxrs-base-2.8.5.jar:/home/bbanner/kafka-1/bin/../libs/jackson-jaxrs-json-provider-2.8.5.jar:/home/bbanner/kafka-1/bin/../libs/jackson-module-jaxb-annotations-2.8.5.jar:/home/bbanner/kafka-1/bin/../libs/javassist-3.20.0-GA.jar:/home/bbanner/kafka-1/bin/../libs/javax.annotation-api-1.2.jar:/home/bbanner/kafka-1/bin/../libs/javax.inject-1.jar:/home/bbanner/kafka-1/bin/../libs/javax.inject-2.5.0-b05.jar:/home/bbanner/kafka-1/bin/../libs/javax.servlet-api-3.1.0.jar:/home/bbanner/kafka-1/bin/../libs/javax.ws.rs-api-2.0.1.jar:/home/bbanner/kafka-1/bin/../libs/jersey-client-2.24.jar:/home/bbanner/kafka-1/bin/../libs/jersey-common-2.24.jar:/home/bbanner/kafka-1/bin/../libs/jersey-container-servlet-2.24.jar:/home/bbanner/kafka-1/bin/../libs/jersey-container-servlet-core-2.24.jar:/home/bbanner/kafka-1/bin/../libs/jersey-guava-2.24.jar:/home/bbanner/kafka-1/bin/../libs/jersey-media-jaxb-2.24.jar:/home/bbanner/kafka-1/bin/../libs/jersey-server-2.24.jar:/home/bbanner/kafka-1/bin/../libs/jetty-continuation-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-http-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-io-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-security-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-server-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-servlet-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-servlets-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-util-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jopt-simple-5.0.3.jar:/home/bbanner/kafka-1/bin/../libs/kafka_2.11-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/kafka_2.11-0.10.2.0-sources.jar:/home/bbanner/kafka-1/bin/../libs/kafka_2.11-0.10.2.0-test-sources.jar:/home/bbanner/kafka-1/bin/../libs/kafka-clients-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/kafka-log4j-appender-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/kafka-streams-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/kafka-streams-examples-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/kafka-tools-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/log4j-1.2.17.jar:/home/bbanner/kafka-1/bin/../libs/lz4-1.3.0.jar:/home/bbanner/kafka-1/bin/../libs/metrics-core-2.2.0.jar:/home/bbanner/kafka-1/bin/../libs/osgi-resource-locator-1.0.1.jar:/home/bbanner/kafka-1/bin/../libs/reflections-0.9.10.jar:/home/bbanner/kafka-1/bin/../libs/rocksdbjni-5.0.1.jar:/home/bbanner/kafka-1/bin/../libs/scala-library-2.11.8.jar:/home/bbanner/kafka-1/bin/../libs/scala-parser-combinators_2.11-1.0.4.jar:/home/bbanner/kafka-1/bin/../libs/slf4j-api-1.7.21.jar:/home/bbanner/kafka-1/bin/../libs/slf4j-log4j12-1.7.21.jar:/home/bbanner/kafka-1/bin/../libs/snappy-java-1.1.2.6.jar:/home/bbanner/kafka-1/bin/../libs/validation-api-1.1.0.Final.jar:/home/bbanner/kafka-1/bin/../libs/zkclient-0.10.jar:/home/bbanner/kafka-1/bin/../libs/zookeeper-3.4.9.jar (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,857] INFO Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,857] INFO Server environment:java.io.tmpdir=/tmp (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,857] INFO Server environment:java.compiler=<NA> (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,857] INFO Server environment:os.name=Linux (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,857] INFO Server environment:os.arch=amd64 (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,857] INFO Server environment:os.version=4.4.0-72-generic (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,858] INFO Server environment:user.name=bbanner (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,858] INFO Server environment:user.home=/home/bbanner (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,858] INFO Server environment:user.dir=/home/bbanner/kafka-1 (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,876] INFO tickTime set to 3000 (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,876] INFO minSessionTimeout set to -1 (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,877] INFO maxSessionTimeout set to -1 (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:15,892] INFO binding to port 0.0.0.0/0.0.0.0:2181 (org.apache.zookeeper.server.NIOServ

I then proceed to start Kafka, and everything seems OK too:

$ bin/kafka-server-start.sh config/server.properties                                                                                                                                                   [152/176]
[2017-04-22 12:25:56,342] INFO KafkaConfig values: 
        advertised.host.name = null
        advertised.listeners = null
        advertised.port = null
        authorizer.class.name = 
        auto.create.topics.enable = true
        auto.leader.rebalance.enable = true
        background.threads = 10
        broker.id = 1
        broker.id.generation.enable = true
        broker.rack = null
        compression.type = producer
        connections.max.idle.ms = 600000
        controlled.shutdown.enable = true
        controlled.shutdown.max.retries = 3
        controlled.shutdown.retry.backoff.ms = 5000
        controller.socket.timeout.ms = 30000
        create.topic.policy.class.name = null
        default.replication.factor = 1
        delete.topic.enable = false
        fetch.purgatory.purge.interval.requests = 1000
        group.max.session.timeout.ms = 300000
        group.min.session.timeout.ms = 6000
        host.name = 
        inter.broker.listener.name = null
        inter.broker.protocol.version = 0.10.2-IV0
        leader.imbalance.check.interval.seconds = 300
        leader.imbalance.per.broker.percentage = 10
        listener.security.protocol.map = SSL:SSL,SASL_PLAINTEXT:SASL_PLAINTEXT,TRACE:TRACE,SASL_SSL:SASL_SSL,PLAINTEXT:PLAINTEXT
        listeners = PLAINTEXT://:19092
        log.cleaner.backoff.ms = 15000
        log.cleaner.dedupe.buffer.size = 134217728
        log.cleaner.delete.retention.ms = 86400000
        log.cleaner.enable = true
        log.cleaner.io.buffer.load.factor = 0.9
        log.cleaner.io.buffer.size = 524288
        log.cleaner.io.max.bytes.per.second = 1.7976931348623157E308
        log.cleaner.min.cleanable.ratio = 0.5
        log.cleaner.min.compaction.lag.ms = 0
        log.cleaner.threads = 1
        log.cleanup.policy = [delete]
        log.dir = /tmp/kafka-logs
        log.dirs = /tmp/kafka-logs-1
        log.flush.interval.messages = 9223372036854775807
        log.flush.interval.ms = null
        log.flush.offset.checkpoint.interval.ms = 60000
        log.flush.scheduler.interval.ms = 9223372036854775807
        log.index.interval.bytes = 4096
        log.index.size.max.bytes = 10485760
        log.message.format.version = 0.10.2-IV0
        log.message.timestamp.difference.max.ms = 9223372036854775807
        log.message.timestamp.type = CreateTime
        log.preallocate = false
        log.retention.bytes = -1
        log.retention.check.interval.ms = 300000
        log.retention.hours = 168
        log.retention.minutes = null
        log.retention.ms = null
        log.roll.hours = 168
        log.roll.jitter.hours = 0
        log.roll.jitter.ms = null
        log.roll.ms = null
        log.segment.bytes = 1073741824
        log.segment.delete.delay.ms = 60000
        max.connections.per.ip = 2147483647
        max.connections.per.ip.overrides =
        message.max.bytes = 1000012
        metric.reporters = []
        metrics.num.samples = 2
        metrics.recording.level = INFO
        metrics.sample.window.ms = 30000
        min.insync.replicas = 1
        num.io.threads = 8
        num.network.threads = 3
        num.partitions = 1
        num.recovery.threads.per.data.dir = 1
        num.replica.fetchers = 1
        offset.metadata.max.bytes = 4096
        offsets.commit.required.acks = -1
        offsets.commit.timeout.ms = 5000
        offsets.load.buffer.size = 5242880
        offsets.retention.check.interval.ms = 600000
        offsets.retention.minutes = 1440
        offsets.topic.compression.codec = 0
        offsets.topic.num.partitions = 50
        offsets.topic.replication.factor = 3
        offsets.topic.segment.bytes = 104857600
        port = 9092
        principal.builder.class = class org.apache.kafka.common.security.auth.DefaultPrincipalBuilder
        producer.purgatory.purge.interval.requests = 1000
        queued.max.requests = 500
        quota.consumer.default = 9223372036854775807
        quota.producer.default = 9223372036854775807
        quota.window.num = 11
        quota.window.size.seconds = 1
        replica.fetch.backoff.ms = 1000
        replica.fetch.max.bytes = 1048576
        replica.fetch.min.bytes = 1
        replica.fetch.response.max.bytes = 10485760
        replica.fetch.wait.max.ms = 500
        replica.high.watermark.checkpoint.interval.ms = 5000
        replica.lag.time.max.ms = 10000
        replica.socket.receive.buffer.bytes = 65536
        replica.socket.timeout.ms = 30000
        replication.quota.window.num = 11
        replication.quota.window.size.seconds = 1
        request.timeout.ms = 30000
        reserved.broker.max.id = 1000
        sasl.enabled.mechanisms = [GSSAPI]
        sasl.kerberos.kinit.cmd = /usr/bin/kinit
        sasl.kerberos.min.time.before.relogin = 60000
        sasl.kerberos.principal.to.local.rules = [DEFAULT]
        sasl.kerberos.service.name = null
        sasl.kerberos.ticket.renew.jitter = 0.05
        sasl.kerberos.ticket.renew.window.factor = 0.8
        sasl.mechanism.inter.broker.protocol = GSSAPI
        security.inter.broker.protocol = PLAINTEXT
        socket.receive.buffer.bytes = 102400
        socket.request.max.bytes = 104857600
        socket.send.buffer.bytes = 102400
        ssl.cipher.suites = null
        ssl.client.auth = none
        ssl.enabled.protocols = [TLSv1.2, TLSv1.1, TLSv1]
        ssl.endpoint.identification.algorithm = null
        ssl.key.password = null
        ssl.keymanager.algorithm = SunX509
        ssl.keystore.location = null
        ssl.keystore.password = null
        ssl.keystore.type = JKS
        ssl.protocol = TLS
        ssl.provider = null
        ssl.secure.random.implementation = null
        ssl.trustmanager.algorithm = PKIX
        ssl.truststore.location = null
        ssl.truststore.password = null
        ssl.truststore.type = JKS
        unclean.leader.election.enable = true
        zookeeper.connect = localhost:2181
        zookeeper.connection.timeout.ms = 6000
        zookeeper.session.timeout.ms = 6000
        zookeeper.set.acl = false
        zookeeper.sync.time.ms = 2000
 (kafka.server.KafkaConfig)
[2017-04-22 12:25:56,419] INFO starting (kafka.server.KafkaServer)
[2017-04-22 12:25:56,422] INFO Connecting to zookeeper on localhost:2181 (kafka.server.KafkaServer)
[2017-04-22 12:25:56,437] INFO Starting ZkClient event thread. (org.I0Itec.zkclient.ZkEventThread)
[2017-04-22 12:25:56,448] INFO Client environment:zookeeper.version=3.4.9-1757313, built on 08/23/2016 06:50 GMT (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,448] INFO Client environment:host.name=10.0.0.4 (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,449] INFO Client environment:java.version=1.8.0_121 (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,449] INFO Client environment:java.vendor=Oracle Corporation (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,449] INFO Client environment:java.home=/usr/lib/jvm/java-8-oracle/jre (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,449] INFO Client environment:java.class.path=:/home/bbanner/kafka-1/bin/../libs/aopalliance-repackaged-2.5.0-b05.jar:/home/bbanner/kafka-1/bin/../libs/argparse4j-0.7.0.jar:/home/bbanner/kafka-1/bin/../libs/con
nect-api-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/connect-file-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/connect-json-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/connect-runtime-0.10.2.0.jar:/home/bbanner/kafka-1/
bin/../libs/connect-transforms-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/guava-18.0.jar:/home/bbanner/kafka-1/bin/../libs/hk2-api-2.5.0-b05.jar:/home/bbanner/kafka-1/bin/../libs/hk2-locator-2.5.0-b05.jar:/home/bbanner/kafk
a-1/bin/../libs/hk2-utils-2.5.0-b05.jar:/home/bbanner/kafka-1/bin/../libs/jackson-annotations-2.8.0.jar:/home/bbanner/kafka-1/bin/../libs/jackson-annotations-2.8.5.jar:/home/bbanner/kafka-1/bin/../libs/jackson-core-2.8.5.jar:/home
/bbanner/kafka-1/bin/../libs/jackson-databind-2.8.5.jar:/home/bbanner/kafka-1/bin/../libs/jackson-jaxrs-base-2.8.5.jar:/home/bbanner/kafka-1/bin/../libs/jackson-jaxrs-json-provider-2.8.5.jar:/home/bbanner/kafka-1/bin/../libs/ja
ckson-module-jaxb-annotations-2.8.5.jar:/home/bbanner/kafka-1/bin/../libs/javassist-3.20.0-GA.jar:/home/bbanner/kafka-1/bin/../libs/javax.annotation-api-1.2.jar:/home/bbanner/kafka-1/bin/../libs/javax.inject-1.jar:/home/bbanner
/kafka-1/bin/../libs/javax.inject-2.5.0-b05.jar:/home/bbanner/kafka-1/bin/../libs/javax.servlet-api-3.1.0.jar:/home/bbanner/kafka-1/bin/../libs/javax.ws.rs-api-2.0.1.jar:/home/bbanner/kafka-1/bin/../libs/jersey-client-2.24.jar:/ho
me/bbanner/kafka-1/bin/../libs/jersey-common-2.24.jar:/home/bbanner/kafka-1/bin/../libs/jersey-container-servlet-2.24.jar:/home/bbanner/kafka-1/bin/../libs/jersey-container-servlet-core-2.24.jar:/home/bbanner/kafka-1/bin/../lib
s/jersey-guava-2.24.jar:/home/bbanner/kafka-1/bin/../libs/jersey-media-jaxb-2.24.jar:/home/bbanner/kafka-1/bin/../libs/jersey-server-2.24.jar:/home/bbanner/kafka-1/bin/../libs/jetty-continuation-9.2.15.v20160210.jar:/home/bmcustod
io/kafka-1/bin/../libs/jetty-http-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-io-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-security-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-s
erver-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-servlet-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-servlets-9.2.15.v20160210.jar:/home/bbanner/kafka-1/bin/../libs/jetty-util-9.2.15.v20160210.ja
r:/home/bbanner/kafka-1/bin/../libs/jopt-simple-5.0.3.jar:/home/bbanner/kafka-1/bin/../libs/kafka_2.11-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/kafka_2.11-0.10.2.0-sources.jar:/home/bbanner/kafka-1/bin/../libs/kafka_2.11-
0.10.2.0-test-sources.jar:/home/bbanner/kafka-1/bin/../libs/kafka-clients-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/kafka-log4j-appender-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/kafka-streams-0.10.2.0.jar:/home/bmcustod
io/kafka-1/bin/../libs/kafka-streams-examples-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/kafka-tools-0.10.2.0.jar:/home/bbanner/kafka-1/bin/../libs/log4j-1.2.17.jar:/home/bbanner/kafka-1/bin/../libs/lz4-1.3.0.jar:/home/bmcusto
dio/kafka-1/bin/../libs/metrics-core-2.2.0.jar:/home/bbanner/kafka-1/bin/../libs/osgi-resource-locator-1.0.1.jar:/home/bbanner/kafka-1/bin/../libs/reflections-0.9.10.jar:/home/bbanner/kafka-1/bin/../libs/rocksdbjni-5.0.1.jar:/home
/bbanner/kafka-1/bin/../libs/scala-library-2.11.8.jar:/home/bbanner/kafka-1/bin/../libs/scala-parser-combinators_2.11-1.0.4.jar:/home/bbanner/kafka-1/bin/../libs/slf4j-api-1.7.21.jar:/home/bbanner/kafka-1/bin/../libs/slf4j-log4
j12-1.7.21.jar:/home/bbanner/kafka-1/bin/../libs/snappy-java-1.1.2.6.jar:/home/bbanner/kafka-1/bin/../libs/validation-api-1.1.0.Final.jar:/home/bbanner/kafka-1/bin/../libs/zkclient-0.10.jar:/home/bbanner/kafka-1/bin/../libs/zoo
keeper-3.4.9.jar (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,450] INFO Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,450] INFO Client environment:java.io.tmpdir=/tmp (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,451] INFO Client environment:java.compiler=<NA> (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,451] INFO Client environment:os.name=Linux (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,451] INFO Client environment:os.arch=amd64 (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,451] INFO Client environment:os.version=4.4.0-72-generic (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,451] INFO Client environment:user.name=bbanner (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,451] INFO Client environment:user.home=/home/bbanner (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,451] INFO Client environment:user.dir=/home/bbanner/kafka-1 (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,453] INFO Initiating client connection, connectString=localhost:2181 sessionTimeout=6000 watcher=org.I0Itec.zkclient.ZkClient@333291e3 (org.apache.zookeeper.ZooKeeper)
[2017-04-22 12:25:56,471] INFO Waiting for keeper state SyncConnected (org.I0Itec.zkclient.ZkClient)
[2017-04-22 12:25:56,475] INFO Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
[2017-04-22 12:25:56,484] INFO Socket connection established to localhost/127.0.0.1:2181, initiating session (org.apache.zookeeper.ClientCnxn)
[2017-04-22 12:25:56,522] INFO Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x15b959f978b0000, negotiated timeout = 6000 (org.apache.zookeeper.ClientCnxn)
[2017-04-22 12:25:56,525] INFO zookeeper state changed (SyncConnected) (org.I0Itec.zkclient.ZkClient)
[2017-04-22 12:25:56,694] INFO Cluster ID = i_Ld0g3xSsS-FviO2qg05A (kafka.server.KafkaServer)
[2017-04-22 12:25:56,698] WARN No meta.properties file under dir /tmp/kafka-logs-1/meta.properties (kafka.server.BrokerMetadataCheckpoint)
[2017-04-22 12:25:56,721] INFO [ThrottledRequestReaper-Fetch], Starting  (kafka.server.ClientQuotaManager$ThrottledRequestReaper)
[2017-04-22 12:25:56,724] INFO [ThrottledRequestReaper-Produce], Starting  (kafka.server.ClientQuotaManager$ThrottledRequestReaper)
[2017-04-22 12:25:56,760] INFO Log directory '/tmp/kafka-logs-1' not found, creating it. (kafka.log.LogManager)
[2017-04-22 12:25:56,770] INFO Loading logs. (kafka.log.LogManager)
[2017-04-22 12:25:56,778] INFO Logs loading complete in 8 ms. (kafka.log.LogManager)
[2017-04-22 12:25:56,855] INFO Starting log cleanup with a period of 300000 ms. (kafka.log.LogManager)
[2017-04-22 12:25:56,857] INFO Starting log flusher with a default period of 9223372036854775807 ms. (kafka.log.LogManager)
[2017-04-22 12:25:56,905] INFO Awaiting socket connections on 0.0.0.0:19092. (kafka.network.Acceptor)
[2017-04-22 12:25:56,918] INFO [Socket Server on Broker 1], Started 1 acceptor threads (kafka.network.SocketServer)
[2017-04-22 12:25:56,938] INFO [ExpirationReaper-1], Starting  (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2017-04-22 12:25:56,939] INFO [ExpirationReaper-1], Starting  (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2017-04-22 12:25:56,983] INFO Creating /controller (is it secure? false) (kafka.utils.ZKCheckedEphemeral)
[2017-04-22 12:25:56,993] INFO Result of znode creation is: OK (kafka.utils.ZKCheckedEphemeral)
[2017-04-22 12:25:56,993] INFO 1 successfully elected as leader (kafka.server.ZookeeperLeaderElector)
[2017-04-22 12:25:57,104] INFO [ExpirationReaper-1], Starting  (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2017-04-22 12:25:57,106] INFO [ExpirationReaper-1], Starting  (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2017-04-22 12:25:57,113] INFO [ExpirationReaper-1], Starting  (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2017-04-22 12:25:57,120] INFO [GroupCoordinator 1]: Starting up. (kafka.coordinator.GroupCoordinator)
[2017-04-22 12:25:57,134] INFO [GroupCoordinator 1]: Startup complete. (kafka.coordinator.GroupCoordinator)
[2017-04-22 12:25:57,135] INFO [Group Metadata Manager on Broker 1]: Removed 0 expired offsets in 2 milliseconds. (kafka.coordinator.GroupMetadataManager)
[2017-04-22 12:25:57,215] INFO Will not load MX4J, mx4j-tools.jar is not in the classpath (kafka.utils.Mx4jLoader$)
[2017-04-22 12:25:57,271] INFO New leader is 1 (kafka.server.ZookeeperLeaderElector$LeaderChangeListener)
[2017-04-22 12:25:57,277] INFO Creating /brokers/ids/1 (is it secure? false) (kafka.utils.ZKCheckedEphemeral)
[2017-04-22 12:25:57,290] INFO Result of znode creation is: OK (kafka.utils.ZKCheckedEphemeral)
[2017-04-22 12:25:57,302] INFO Registered broker 1 at path /brokers/ids/1 with addresses: EndPoint(10.0.0.4,19092,ListenerName(PLAINTEXT),PLAINTEXT) (kafka.utils.ZkUtils)
[2017-04-22 12:25:57,303] WARN No meta.properties file under dir /tmp/kafka-logs-1/meta.properties (kafka.server.BrokerMetadataCheckpoint)
[2017-04-22 12:25:57,347] INFO Kafka version : 0.10.2.0 (org.apache.kafka.common.utils.AppInfoParser)
[2017-04-22 12:25:57,347] INFO Kafka commitId : 576d93a8dc0cf421 (org.apache.kafka.common.utils.AppInfoParser)
[2017-04-22 12:25:57,348] INFO [Kafka Server 1], started (kafka.server.KafkaServer)

However, I get the following entries in the ZooKeeper logs:

[2017-04-22 12:25:56,483] INFO Accepted socket connection from /127.0.0.1:55376 (org.apache.zookeeper.server.NIOServerCnxnFactory)
[2017-04-22 12:25:56,494] INFO Client attempting to establish new session at /127.0.0.1:55376 (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:56,497] INFO Creating new log file: log.1 (org.apache.zookeeper.server.persistence.FileTxnLog)
[2017-04-22 12:25:56,520] INFO Established session 0x15b959f978b0000 with negotiated timeout 6000 for client /127.0.0.1:55376 (org.apache.zookeeper.server.ZooKeeperServer)
[2017-04-22 12:25:56,566] INFO Got user-level KeeperException when processing sessionid:0x15b959f978b0000 type:create cxid:0x5 zxid:0x3 txntype:-1 reqpath:n/a Error Path:/brokers Error:KeeperErrorCode = NoNode for /brokers (org.apache.zookeeper.server.PrepRequestProcessor)
[2017-04-22 12:25:56,599] INFO Got user-level KeeperException when processing sessionid:0x15b959f978b0000 type:create cxid:0xb zxid:0x7 txntype:-1 reqpath:n/a Error Path:/config Error:KeeperErrorCode = NoNode for /config (org.apache.zookeeper.server.PrepRequestProcessor)
[2017-04-22 12:25:56,624] INFO Got user-level KeeperException when processing sessionid:0x15b959f978b0000 type:create cxid:0x13 zxid:0xc txntype:-1 reqpath:n/a Error Path:/admin Error:KeeperErrorCode = NoNode for /admin (org.apache.zookeeper.server.PrepRequestProcessor)
[2017-04-22 12:25:56,683] INFO Got user-level KeeperException when processing sessionid:0x15b959f978b0000 type:create cxid:0x1b zxid:0x11 txntype:-1 reqpath:n/a Error Path:/cluster Error:KeeperErrorCode = NoNode for /cluster (org.apache.zookeeper.server.PrepRequestProcessor)
[2017-04-22 12:25:56,999] INFO Got user-level KeeperException when processing sessionid:0x15b959f978b0000 type:setData cxid:0x25 zxid:0x15 txntype:-1 reqpath:n/a Error Path:/controller_epoch Error:KeeperErrorCode = NoNode for /controller_epoch (org.apache.zookeeper.server.PrepRequestProcessor)
[2017-04-22 12:25:57,088] INFO Got user-level KeeperException when processing sessionid:0x15b959f978b0000 type:delete cxid:0x36 zxid:0x17 txntype:-1 reqpath:n/a Error Path:/admin/preferred_replica_election Error:KeeperErrorCode = NoNode for /admin/preferred_replica_election (org.apache.zookeeper.server.PrepRequestProcessor)
[2017-04-22 12:25:57,278] INFO Got user-level KeeperException when processing sessionid:0x15b959f978b0000 type:create cxid:0x41 zxid:0x18 txntype:-1 reqpath:n/a Error Path:/brokers Error:KeeperErrorCode = NodeExists for /brokers (org.apache.zookeeper.server.PrepRequestProcessor)
[2017-04-22 12:25:57,279] INFO Got user-level KeeperException when processing sessionid:0x15b959f978b0000 type:create cxid:0x42 zxid:0x19 txntype:-1 reqpath:n/a Error Path:/brokers/ids Error:KeeperErrorCode = NodeExists for /brokers/ids (org.apache.zookeeper.server.PrepRequestProcessor)

Although there are no errors in Kafka, I don't know what these

Got user-level KeeperException when processing (...)

messages mean, and I'm not confident on the setup. What do these messages mean? Have I misconfigured something?

PS—Running bin/kafka-topics.sh --create --zookeeper localhost:2181 --replication-factor 1 --partitions 1 --topic test as per the docs also originates this kind of messages:

(...)
[2017-04-22 12:48:10,001] INFO Got user-level KeeperException when processing sessionid:0x15b959f978b0001 type:setData cxid:0x4 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/config/topics/test Error:KeeperErrorCode = NoNode for /config/topics/test (org.apache.zookeeper.server.PrepRequestProcessor)
[2017-04-22 12:48:10,014] INFO Got user-level KeeperException when processing sessionid:0x15b959f978b0001 type:create cxid:0x6 zxid:0x1d txntype:-1 reqpath:n/a Error Path:/config/topics Error:KeeperErrorCode = NodeExists for /config/topics (org.apache.zookeeper.server.PrepRequestProcessor)
(...)
[2017-04-22 12:48:10,077] INFO Got user-level KeeperException when processing sessionid:0x15b959f978b0000 type:create cxid:0x4c zxid:0x21 txntype:-1 reqpath:n/a Error Path:/brokers/topics/test/partitions/0 Error:KeeperErrorCode = NoNode for /brokers/topics/test/partitions/0 (org.apache.zookeeper.server.PrepRequestProcessor)
[2017-04-22 12:48:10,080] INFO Got user-level KeeperException when processing sessionid:0x15b959f978b0000 type:create cxid:0x4d zxid:0x22 txntype:-1 reqpath:n/a Error Path:/brokers/topics/test/partitions Error:KeeperErrorCode = NoNode for /brokers/topics/test/partitions (org.apache.zookeeper.server.PrepRequestProcessor)

Mulder answered 22/4, 2017 at 12:40 Comment(7)
Doesn't it just mean that at startup some ephemeral nodes don't yet exist?Atbara
There are both NoNode and NodeExists errors. Also, one would think that this is a first-time setup issue, but restarting Kafka results in the same kind of entries.Mulder
Ephemeral nodes disappear once the connection is lost.Atbara
So, are these entries normal and expectable then?Mulder
Yes. It's confusing but normal.Atbara
@B.Banner did you manage to solve this issue? i'm getting the same error on my setupBrio
Was this solved?Nous
S
54

The message you see is not an error yet. It is a potential exception raised by Zookeeper that original object making a request has to handle.

When you start a fresh Kafka, it gets a bunch of NoNode messages. It's normal because some paths don't exist yet. At the same time, you get also NodeExists messages as the path exists already.

Example: Error:KeeperErrorCode = NoNode for /config/topics/test It's because Kafka sends a request to Zookeeper for this path. But it doesn't exist. That's OK, because you are trying to create it. So, you see "INFO" from Zookeeper but no error from Kafka. Once Kafka gets this message, it tries to create your topic. To do so, it needs to access a path in Zookeeper for topics. So, it sends a request and gets an error NodeExists for /config/topics. Again, it's normal and Kafka ignores the message.

Long story short, these are all non-issue messages and you should skip them. If it bothers you, change logging configuration of Zookeeper (it's not recommended though).

Spile answered 2/1, 2018 at 19:56 Comment(0)

© 2022 - 2024 — McMap. All rights reserved.