Page MenuHomePhabricator

Vagrant's /var/log/daemon.log filling up with kafka errors
Open, MediumPublic

Description

/var/log/daemon.log is accumulating lots of errors from kafka. I noticed this was an issue after I realized my VM was out of space, investigated, and deleted 8GB of daemon.log.

Here's a few seconds worth of the errors:

vagrant@vagrant:/var/log$ sudo tail -f daemon.log
Feb 12 18:24:05 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:05 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:05 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
Feb 12 18:24:05 vagrant kafka-server-start[1513]: [2018-02-12 18:24:05,511] INFO Opening socket connection to server localhost/0:0:0:0:0:0:0:1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:05 vagrant kafka-server-start[1513]: [2018-02-12 18:24:05,511] WARN Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:05 vagrant kafka-server-start[1513]: java.net.ConnectException: Connection refused
Feb 12 18:24:05 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
Feb 12 18:24:05 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:05 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:05 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
Feb 12 18:24:06 vagrant kafka-server-start[1513]: [2018-02-12 18:24:06,612] INFO Opening socket connection to server vagrant.mediawiki-vagrant.dev/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:06 vagrant kafka-server-start[1513]: [2018-02-12 18:24:06,612] WARN Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:06 vagrant kafka-server-start[1513]: java.net.ConnectException: Connection refused
Feb 12 18:24:06 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
Feb 12 18:24:06 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:06 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:06 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
Feb 12 18:24:06 vagrant kafka-server-start[1513]: [2018-02-12 18:24:06,713] INFO Opening socket connection to server localhost/0:0:0:0:0:0:0:1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:06 vagrant kafka-server-start[1513]: [2018-02-12 18:24:06,713] WARN Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:06 vagrant kafka-server-start[1513]: java.net.ConnectException: Connection refused
Feb 12 18:24:06 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
Feb 12 18:24:06 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:06 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:06 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
Feb 12 18:24:07 vagrant kafka-server-start[1513]: [2018-02-12 18:24:07,814] INFO Opening socket connection to server vagrant.mediawiki-vagrant.dev/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:07 vagrant kafka-server-start[1513]: [2018-02-12 18:24:07,814] WARN Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:07 vagrant kafka-server-start[1513]: java.net.ConnectException: Connection refused
Feb 12 18:24:07 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
Feb 12 18:24:07 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:07 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:07 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
Feb 12 18:24:07 vagrant kafka-server-start[1513]: [2018-02-12 18:24:07,914] INFO Opening socket connection to server localhost/0:0:0:0:0:0:0:1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:07 vagrant kafka-server-start[1513]: [2018-02-12 18:24:07,915] WARN Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:07 vagrant kafka-server-start[1513]: java.net.ConnectException: Connection refused
Feb 12 18:24:07 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
Feb 12 18:24:07 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:07 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:07 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
Feb 12 18:24:09 vagrant kafka-server-start[1513]: [2018-02-12 18:24:09,015] INFO Opening socket connection to server vagrant.mediawiki-vagrant.dev/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:09 vagrant kafka-server-start[1513]: [2018-02-12 18:24:09,016] WARN Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:09 vagrant kafka-server-start[1513]: java.net.ConnectException: Connection refused
Feb 12 18:24:09 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
Feb 12 18:24:09 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:09 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:09 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
Feb 12 18:24:09 vagrant kafka-server-start[1513]: [2018-02-12 18:24:09,116] INFO Opening socket connection to server localhost/0:0:0:0:0:0:0:1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:09 vagrant kafka-server-start[1513]: [2018-02-12 18:24:09,117] WARN Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:09 vagrant kafka-server-start[1513]: java.net.ConnectException: Connection refused
Feb 12 18:24:09 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
Feb 12 18:24:09 vagrant kafka-server-start[1513]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:09 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:09 vagrant kafka-server-start[1513]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: [2018-02-12 18:24:10,176] INFO Terminate ZkClient event thread. (org.I0Itec.zkclient.ZkEventThread)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: [2018-02-12 18:24:10,217] INFO Opening socket connection to server vagrant.mediawiki-vagrant.dev/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: [2018-02-12 18:24:10,319] INFO Session: 0x0 closed (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: [2018-02-12 18:24:10,322] INFO EventThread shut down for session: 0x0 (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: [2018-02-12 18:24:10,320] FATAL Fatal error during KafkaServer startup. Prepare to shutdown (kafka.server.KafkaServer)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: org.I0Itec.zkclient.exception.ZkTimeoutException: Unable to connect to zookeeper server 'localhost:2181' with timeout of 6000 ms
Feb 12 18:24:10 vagrant kafka-server-start[1513]: #011at org.I0Itec.zkclient.ZkClient.connect(ZkClient.java:1233)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: #011at org.I0Itec.zkclient.ZkClient.<init>(ZkClient.java:157)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: #011at org.I0Itec.zkclient.ZkClient.<init>(ZkClient.java:131)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: #011at kafka.utils.ZkUtils$.createZkClientAndConnection(ZkUtils.scala:115)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: #011at kafka.utils.ZkUtils$.withMetrics(ZkUtils.scala:92)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: #011at kafka.server.KafkaServer.initZk(KafkaServer.scala:346)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: #011at kafka.server.KafkaServer.startup(KafkaServer.scala:194)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: #011at io.confluent.support.metrics.SupportedServerStartable.startup(SupportedServerStartable.java:112)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: #011at io.confluent.support.metrics.SupportedKafka.main(SupportedKafka.java:58)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: [2018-02-12 18:24:10,325] INFO shutting down (kafka.server.KafkaServer)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: [2018-02-12 18:24:10,339] INFO shut down completed (kafka.server.KafkaServer)
Feb 12 18:24:10 vagrant kafka-server-start[1513]: [2018-02-12 18:24:10,341] INFO shutting down (kafka.server.KafkaServer)
Feb 12 18:24:10 vagrant systemd[1]: kafka.service: Main process exited, code=exited, status=1/FAILURE
Feb 12 18:24:10 vagrant systemd[1]: kafka.service: Unit entered failed state.
Feb 12 18:24:10 vagrant systemd[1]: kafka.service: Failed with result 'exit-code'.
Feb 12 18:24:10 vagrant systemd[1]: kafka.service: Service hold-off time over, scheduling restart.
Feb 12 18:24:10 vagrant systemd[1]: Stopped Kafka Broker.
Feb 12 18:24:10 vagrant systemd[1]: Started Kafka Broker.
Feb 12 18:24:11 vagrant kafka-server-start[1574]: [2018-02-12 18:24:11,997] INFO KafkaConfig values:
Feb 12 18:24:11 vagrant kafka-server-start[1574]: #011advertised.host.name = null
Feb 12 18:24:11 vagrant kafka-server-start[1574]: #011advertised.listeners = null
Feb 12 18:24:11 vagrant kafka-server-start[1574]: #011advertised.port = null
Feb 12 18:24:11 vagrant kafka-server-start[1574]: #011alter.config.policy.class.name = null
Feb 12 18:24:11 vagrant kafka-server-start[1574]: #011authorizer.class.name =
Feb 12 18:24:11 vagrant kafka-server-start[1574]: #011auto.create.topics.enable = true
Feb 12 18:24:11 vagrant kafka-server-start[1574]: #011auto.leader.rebalance.enable = true
Feb 12 18:24:11 vagrant kafka-server-start[1574]: #011background.threads = 10
Feb 12 18:24:11 vagrant kafka-server-start[1574]: #011broker.id = 0
Feb 12 18:24:11 vagrant kafka-server-start[1574]: #011broker.id.generation.enable = true
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011broker.interceptor.class = class org.apache.kafka.server.interceptor.DefaultBrokerInterceptor
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011broker.rack = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011compression.type = producer
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011connections.max.idle.ms = 600000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011controlled.shutdown.enable = true
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011controlled.shutdown.max.retries = 3
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011controlled.shutdown.retry.backoff.ms = 5000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011controller.socket.timeout.ms = 30000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011create.topic.policy.class.name = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011default.replication.factor = 1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011delete.records.purgatory.purge.interval.requests = 1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011delete.topic.enable = true
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011fetch.purgatory.purge.interval.requests = 1000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011group.initial.rebalance.delay.ms = 3000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011group.max.session.timeout.ms = 300000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011group.min.session.timeout.ms = 6000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011host.name =
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011inter.broker.listener.name = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011inter.broker.protocol.version = 1.0-IV0
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011leader.imbalance.check.interval.seconds = 300
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011leader.imbalance.per.broker.percentage = 10
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011listener.security.protocol.map = PLAINTEXT:PLAINTEXT,SSL:SSL,SASL_PLAINTEXT:SASL_PLAINTEXT,SASL_SSL:SASL_SSL
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011listeners = PLAINTEXT://:9092
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.cleaner.backoff.ms = 15000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.cleaner.dedupe.buffer.size = 134217728
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.cleaner.delete.retention.ms = 86400000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.cleaner.enable = true
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.cleaner.io.buffer.load.factor = 0.9
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.cleaner.io.buffer.size = 524288
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.cleaner.io.max.bytes.per.second = 1.7976931348623157E308
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.cleaner.min.cleanable.ratio = 0.5
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.cleaner.min.compaction.lag.ms = 0
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.cleaner.threads = 1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.cleanup.policy = [delete]
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.dir = /tmp/kafka-logs
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.dirs = /var/lib/kafka
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.flush.interval.messages = 9223372036854775807
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.flush.interval.ms = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.flush.offset.checkpoint.interval.ms = 60000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.flush.scheduler.interval.ms = 9223372036854775807
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.flush.start.offset.checkpoint.interval.ms = 60000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.index.interval.bytes = 4096
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.index.size.max.bytes = 10485760
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.message.format.version = 1.0-IV0
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.message.timestamp.difference.max.ms = 9223372036854775807
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.message.timestamp.type = CreateTime
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.preallocate = false
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.retention.bytes = -1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.retention.check.interval.ms = 300000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.retention.hours = 168
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.retention.minutes = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.retention.ms = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.roll.hours = 168
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.roll.jitter.hours = 0
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.roll.jitter.ms = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.roll.ms = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.segment.bytes = 1073741824
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011log.segment.delete.delay.ms = 60000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011max.connections.per.ip = 2147483647
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011max.connections.per.ip.overrides =
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011message.max.bytes = 1000012
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011metric.reporters = []
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011metrics.num.samples = 2
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011metrics.recording.level = INFO
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011metrics.sample.window.ms = 30000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011min.insync.replicas = 1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011num.io.threads = 8
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011num.network.threads = 3
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011num.partitions = 1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011num.recovery.threads.per.data.dir = 1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011num.replica.fetchers = 1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011offset.metadata.max.bytes = 4096
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011offsets.commit.required.acks = -1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011offsets.commit.timeout.ms = 5000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011offsets.load.buffer.size = 5242880
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011offsets.retention.check.interval.ms = 600000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011offsets.retention.minutes = 1440
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011offsets.topic.compression.codec = 0
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011offsets.topic.num.partitions = 50
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011offsets.topic.replication.factor = 3
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011offsets.topic.segment.bytes = 104857600
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011port = 9092
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011principal.builder.class = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011producer.purgatory.purge.interval.requests = 1000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011queued.max.request.bytes = -1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011queued.max.requests = 500
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011quota.consumer.default = 9223372036854775807
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011quota.producer.default = 9223372036854775807
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011quota.window.num = 11
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011quota.window.size.seconds = 1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011replica.fetch.backoff.ms = 1000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011replica.fetch.max.bytes = 1048576
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011replica.fetch.min.bytes = 1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011replica.fetch.response.max.bytes = 10485760
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011replica.fetch.wait.max.ms = 500
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011replica.high.watermark.checkpoint.interval.ms = 5000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011replica.lag.time.max.ms = 10000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011replica.socket.receive.buffer.bytes = 65536
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011replica.socket.timeout.ms = 30000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011replication.quota.window.num = 11
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011replication.quota.window.size.seconds = 1
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011request.timeout.ms = 30000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011reserved.broker.max.id = 1000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011sasl.enabled.mechanisms = [GSSAPI]
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011sasl.kerberos.kinit.cmd = /usr/bin/kinit
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011sasl.kerberos.min.time.before.relogin = 60000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011sasl.kerberos.principal.to.local.rules = [DEFAULT]
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011sasl.kerberos.service.name = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011sasl.kerberos.ticket.renew.jitter = 0.05
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011sasl.kerberos.ticket.renew.window.factor = 0.8
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011sasl.mechanism.inter.broker.protocol = GSSAPI
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011security.inter.broker.protocol = PLAINTEXT
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011socket.receive.buffer.bytes = 102400
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011socket.request.max.bytes = 104857600
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011socket.send.buffer.bytes = 102400
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.cipher.suites = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.client.auth = none
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.enabled.protocols = [TLSv1.2, TLSv1.1, TLSv1]
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.endpoint.identification.algorithm = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.key.password = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.keymanager.algorithm = SunX509
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.keystore.location = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.keystore.password = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.keystore.type = JKS
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.protocol = TLS
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.provider = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.secure.random.implementation = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.trustmanager.algorithm = PKIX
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.truststore.location = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.truststore.password = null
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011ssl.truststore.type = JKS
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011transaction.abort.timed.out.transaction.cleanup.interval.ms = 60000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011transaction.max.timeout.ms = 900000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011transaction.remove.expired.transaction.cleanup.interval.ms = 3600000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011transaction.state.log.load.buffer.size = 5242880
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011transaction.state.log.min.isr = 2
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011transaction.state.log.num.partitions = 50
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011transaction.state.log.replication.factor = 3
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011transaction.state.log.segment.bytes = 104857600
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011transactional.id.expiration.ms = 604800000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011unclean.leader.election.enable = false
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011zookeeper.connect = localhost:2181
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011zookeeper.connection.timeout.ms = 6000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011zookeeper.session.timeout.ms = 6000
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011zookeeper.set.acl = false
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011zookeeper.sync.time.ms = 2000
Feb 12 18:24:12 vagrant kafka-server-start[1574]:  (kafka.server.KafkaConfig)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,200] WARN The support metrics collection feature ("Metrics") of Proactive Support is disabled. (io.confluent.support.metrics.SupportedServerStartable)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,203] INFO starting (kafka.server.KafkaServer)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,207] INFO Connecting to zookeeper on localhost:2181 (kafka.server.KafkaServer)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,228] INFO Client environment:zookeeper.version=3.4.10-39d3a4f269333c922ed3db283be479f9deacaa0f, built on 03/23/2017 10:13 GMT (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,230] INFO Starting ZkClient event thread. (org.I0Itec.zkclient.ZkEventThread)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,232] INFO Client environment:host.name=vagrant.mediawiki-vagrant.dev (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,233] INFO Client environment:java.version=1.8.0_151 (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,234] INFO Client environment:java.vendor=Oracle Corporation (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,235] INFO Client environment:java.home=/usr/lib/jvm/java-8-openjdk-amd64/jre (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,236] INFO Client environment:java.class.path=:/usr/bin/../share/java/kafka/kafka_2.11-1.0.0-cp1.jar:/usr/bin/../share/java/kafka/hk2-api-2.5.0-b32.jar:/usr/bin/../share/java/kafka/javax.ws.rs-api-2.0.1.jar:/usr/bin/../share/java/kafka/jersey-container-servlet-2.25.1.jar:/usr/bin/../share/java/kafka/commons-lang3-3.5.jar:/usr/bin/../share/java/kafka/kafka.jar:/usr/bin/../share/java/kafka/commons-validator-1.4.1.jar:/usr/bin/../share/java/kafka/rocksdbjni-5.7.3.jar:/usr/bin/../share/java/kafka/httpcore-4.4.4.jar:/usr/bin/../share/java/kafka/jackson-module-jaxb-annotations-2.9.1.jar:/usr/bin/../share/java/kafka/jersey-guava-2.25.1.jar:/usr/bin/../share/java/kafka/jackson-mapper-asl-1.9.13.jar:/usr/bin/../share/java/kafka/jackson-databind-2.9.1.jar:/usr/bin/../share/java/kafka/jopt-simple-5.0.4.jar:/usr/bin/../share/java/kafka/zookeeper-3.4.10.jar:/usr/bin/../share/java/kafka/reflections-0.9.11.jar:/usr/bin/../share/java/kafka/argparse4j-0.7.0.jar:/usr/bin/../share/java/kafka/jersey-server-2.25.1.jar:/usr/bin/../share/java/kafka/log4j-1.2.17.jar:/usr/bin/../share/java/kafka/javassist-3.20.0-GA.jar:/usr/bin/../share/java/kafka/jackson-jaxrs-base-2.9.1.jar:/usr/bin/../share/java/kafka/avro-1.8.2.jar:/usr/bin/../share/java/kafka/jetty-http-9.2.22.v20170606.jar:/usr/bin/../share/java/kafka/kafka-log4j-appender-1.0.0-cp1.jar:/usr/bin/../share/java/kafka/javax.inject-2.5.0-b32.jar:/usr/bin/../share/java/kafka/commons-compress-1.8.1.jar:/usr/bin/../share/java/kafka/commons-lang3-3.1.jar:/usr/bin/../share/java/kafka/validation-api-1.1.0.Final.jar:/usr/bin/../share/java/kafka/jetty-servlets-9.2.22.v20170606.jar:/usr/bin/../share/java/kafka/plexus-utils-3.0.24.jar:/usr/bin/../share/java/kafka/aopalliance-repackaged-2.5.0-b32.jar:/usr/bin/../share/java/kafka/jackson-jaxrs-json-provider-2.9.1.jar:/usr/bin/../share/java/kafka/jetty-io-9.2.22.v20170606.jar:/usr/bin/../share/java/kafka/kafka_2.11-1.0.0-cp1-test.jar:/usr/bin/../share/java/kafka/jackson-core-asl-1.9.13.jar:/usr/bin/../share/java/kafka/kafka_2.11-
Feb 12 18:24:12 vagrant kafka-server-start[1574]: 1.0.0-cp1-javadoc.jar:/usr/bin/../share/java/kafka/kafka-streams-examples-1.0.0-cp1.jar:/usr/bin/../share/java/kafka/jersey-container-servlet-core-2.25.1.jar:/usr/bin/../share/java/kafka/osgi-resource-locator-1.0.1.jar:/usr/bin/../share/java/kafka/commons-digester-1.8.1.jar:/usr/bin/../share/java/kafka/metrics-core-2.2.0.jar:/usr/bin/../share/java/kafka/connect-api-1.0.0-cp1.jar:/usr/bin/../share/java/kafka/commons-beanutils-1.8.3.jar:/usr/bin/../share/java/kafka/support-metrics-client-4.0.0.jar:/usr/bin/../share/java/kafka/slf4j-log4j12-1.7.25.jar:/usr/bin/../share/java/kafka/paranamer-2.7.jar:/usr/bin/../share/java/kafka/snappy-java-1.1.4.jar:/usr/bin/../share/java/kafka/kafka-tools-1.0.0-cp1.jar:/usr/bin/../share/java/kafka/commons-logging-1.2.jar:/usr/bin/../share/java/kafka/jetty-continuation-9.2.22.v20170606.jar:/usr/bin/../share/java/kafka/javassist-3.21.0-GA.jar:/usr/bin/../share/java/kafka/connect-transforms-1.0.0-cp1.jar:/usr/bin/../share/java/kafka/kafka_2.11-1.0.0-cp1-test-sources.jar:/usr/bin/../share/java/kafka/kafka_2.11-1.0.0-cp1-scaladoc.jar:/usr/bin/../share/java/kafka/support-metrics-common-4.0.0.jar:/usr/bin/../share/java/kafka/connect-file-1.0.0-cp1.jar:/usr/bin/../share/java/kafka/jetty-servlet-9.2.22.v20170606.jar:/usr/bin/../share/java/kafka/jackson-core-2.9.1.jar:/usr/bin/../share/java/kafka/kafka_2.11-1.0.0-cp1-sources.jar:/usr/bin/../share/java/kafka/slf4j-api-1.7.25.jar:/usr/bin/../share/java/kafka/commons-codec-1.9.jar:/usr/bin/../share/java/kafka/jersey-client-2.25.1.jar:/usr/bin/../share/java/kafka/kafka-streams-1.0.0-cp1.jar:/usr/bin/../share/java/kafka/xz-1.5.jar:/usr/bin/../share/java/kafka/javax.annotation-api-1.2.jar:/usr/bin/../share/java/kafka/jersey-common-2.25.1.jar:/usr/bin/../share/java/kafka/connect-json-1.0.0-cp1.jar:/usr/bin/../share/java/kafka/guava-20.0.jar:/usr/bin/../share/java/kafka/connect-runtime-1.0.0-cp1.jar:/usr/bin/../share/java/kafka/hk2-utils-2.5.0-b32.jar:/usr/bin/../share/java/kafka/jersey-media-jaxb-2.25.1.jar:/usr/bin/../share/java/kafka/zkclient-0.10.
Feb 12 18:24:12 vagrant kafka-server-start[1574]: jar:/usr/bin/../share/java/kafka/hk2-locator-2.5.0-b32.jar:/usr/bin/../share/java/kafka/lz4-java-1.4.jar:/usr/bin/../share/java/kafka/jetty-util-9.2.22.v20170606.jar:/usr/bin/../share/java/kafka/httpmime-4.5.2.jar:/usr/bin/../share/java/kafka/scala-library-2.11.11.jar:/usr/bin/../share/java/kafka/javax.inject-1.jar:/usr/bin/../share/java/kafka/javax.servlet-api-3.1.0.jar:/usr/bin/../share/java/kafka/jetty-security-9.2.22.v20170606.jar:/usr/bin/../share/java/kafka/commons-collections-3.2.1.jar:/usr/bin/../share/java/kafka/kafka-clients-1.0.0-cp1.jar:/usr/bin/../share/java/kafka/jackson-annotations-2.9.1.jar:/usr/bin/../share/java/kafka/maven-artifact-3.5.0.jar:/usr/bin/../share/java/kafka/httpclient-4.5.2.jar:/usr/bin/../share/java/kafka/jetty-server-9.2.22.v20170606.jar:/usr/bin/../share/java/confluent-support-metrics/*:/usr/share/java/confluent-support-metrics/* (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,239] INFO Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,240] INFO Client environment:java.io.tmpdir=/tmp (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,241] INFO Client environment:java.compiler=<NA> (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,241] INFO Client environment:os.name=Linux (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,241] INFO Client environment:os.arch=amd64 (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,241] INFO Client environment:os.version=4.9.0-4-amd64 (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,241] INFO Client environment:user.name=kafka (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,241] INFO Client environment:user.home=/nonexistent (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,241] INFO Client environment:user.dir=/ (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,245] INFO Initiating client connection, connectString=localhost:2181 sessionTimeout=6000 watcher=org.I0Itec.zkclient.ZkClient@10e31a9a (org.apache.zookeeper.ZooKeeper)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,276] INFO Opening socket connection to server vagrant.mediawiki-vagrant.dev/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,279] INFO Waiting for keeper state SyncConnected (org.I0Itec.zkclient.ZkClient)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,285] WARN Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: java.net.ConnectException: Connection refused
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,390] INFO Opening socket connection to server localhost/0:0:0:0:0:0:0:1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: [2018-02-12 18:24:12,392] WARN Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: java.net.ConnectException: Connection refused
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:12 vagrant kafka-server-start[1574]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
Feb 12 18:24:13 vagrant kafka-server-start[1574]: [2018-02-12 18:24:13,494] INFO Opening socket connection to server vagrant.mediawiki-vagrant.dev/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:13 vagrant kafka-server-start[1574]: [2018-02-12 18:24:13,494] WARN Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:13 vagrant kafka-server-start[1574]: java.net.ConnectException: Connection refused
Feb 12 18:24:13 vagrant kafka-server-start[1574]: #011at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
Feb 12 18:24:13 vagrant kafka-server-start[1574]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:13 vagrant kafka-server-start[1574]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:13 vagrant kafka-server-start[1574]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
Feb 12 18:24:13 vagrant kafka-server-start[1574]: [2018-02-12 18:24:13,595] INFO Opening socket connection to server localhost/0:0:0:0:0:0:0:1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:13 vagrant kafka-server-start[1574]: [2018-02-12 18:24:13,595] WARN Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:13 vagrant kafka-server-start[1574]: java.net.ConnectException: Connection refused
Feb 12 18:24:13 vagrant kafka-server-start[1574]: #011at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
Feb 12 18:24:13 vagrant kafka-server-start[1574]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:13 vagrant kafka-server-start[1574]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:13 vagrant kafka-server-start[1574]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
Feb 12 18:24:14 vagrant kafka-server-start[1574]: [2018-02-12 18:24:14,696] INFO Opening socket connection to server vagrant.mediawiki-vagrant.dev/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:14 vagrant kafka-server-start[1574]: [2018-02-12 18:24:14,696] WARN Session 0x0 for server null, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
Feb 12 18:24:14 vagrant kafka-server-start[1574]: java.net.ConnectException: Connection refused
Feb 12 18:24:14 vagrant kafka-server-start[1574]: #011at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
Feb 12 18:24:14 vagrant kafka-server-start[1574]: #011at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
Feb 12 18:24:14 vagrant kafka-server-start[1574]: #011at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
Feb 12 18:24:14 vagrant kafka-server-start[1574]: #011at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
^C

I've just completed a full cycle of vagrant git-update and restarting the VM, which hasn't impacted the errors noticeably.

I don't have the kafka role explicitly installed.

Event Timeline

DLynch created this task.Feb 12 2018, 6:29 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptFeb 12 2018, 6:29 PM

I speculatively explicitly enabled the kafka role, and it doesn't change anything.

Let's see... on the VM, more checking turns up:

vagrant@vagrant:/var/log$ systemctl --state=failed
  UNIT                                  LOAD   ACTIVE SUB    DESCRIPTION
● eventlogging-devserver.service        loaded failed failed EventLogging Dev Server
● eventlogging-service-eventbus.service loaded failed failed EventLogging Produce HTTP Service
● zookeeper.service                     loaded failed failed Coordination service for distributed applications

kafka.service thinks it's running fine, though, despite all the "can't connect to Kafka" errors.

Since, obviously, kafka has never worked on my VM, I'm operating under the assumption that just disabling these constant attempts to launch kafka won't make my situation any *worse*, and I'm trying:

sudo systemctl stop kafka.service

This does, indeed, stop daemon.log growing, and seems to leave me with a perfectly functional mediawiki instance. I imagine puppet will re-break it for me shortly, though.

fdans triaged this task as Medium priority.Apr 19 2018, 4:47 PM
fdans moved this task from Incoming to Operational Excellence on the Analytics board.

@DLynch, do you have another Kafka dependent puppet role enabled? E.g. eventbus or eventlogging?

It looks like Kafka is failing because your Zookeeper service is not up and running. It can't reproduce this since both Zookeeper and Kafka run fine in my VM.

What happens if you run sudo systemctl start zookeeper? Does it start? If not, are there any errors in /var/log/zookeeper/zookeeper.log?

I have eventbus explicitly enabled, but I think I remember that being something I did on a suggestion from someone helping me debug this in IRC. My VM's setup very much comes from vagrant enable role visualeditor and then whatever falls in from that and a few other extensions.

Zookeeper also errors out:

2018-08-14 14:53:46,079 - INFO  [main:QuorumPeerConfig@124] - Reading configuration from: /etc/zookeeper/conf/zoo.cfg
2018-08-14 14:53:46,089 - INFO  [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3
2018-08-14 14:53:46,090 - INFO  [main:DatadirCleanupManager@79] - autopurge.purgeInterval set to 0
2018-08-14 14:53:46,090 - INFO  [main:DatadirCleanupManager@101] - Purge task is not scheduled.
2018-08-14 14:53:46,092 - WARN  [main:QuorumPeerMain@113] - Either no config or no quorum defined in config, running  in standalone mode
2018-08-14 14:53:46,131 - INFO  [main:QuorumPeerConfig@124] - Reading configuration from: /etc/zookeeper/conf/zoo.cfg
2018-08-14 14:53:46,134 - INFO  [main:ZooKeeperServerMain@96] - Starting server
2018-08-14 14:53:46,179 - INFO  [main:Environment@100] - Server environment:zookeeper.version=3.4.9-3--1, built on Thu, 01 Jun 2017 16:26:44 -0700
2018-08-14 14:53:46,179 - INFO  [main:Environment@100] - Server environment:host.name=vagrant.mediawiki-vagrant.dev
2018-08-14 14:53:46,179 - INFO  [main:Environment@100] - Server environment:java.version=1.8.0_151
2018-08-14 14:53:46,179 - INFO  [main:Environment@100] - Server environment:java.vendor=Oracle Corporation
2018-08-14 14:53:46,179 - INFO  [main:Environment@100] - Server environment:java.home=/usr/lib/jvm/java-8-openjdk-amd64/jre
2018-08-14 14:53:46,179 - INFO  [main:Environment@100] - Server environment:java.class.path=/etc/zookeeper/conf:/usr/share/java/jline.jar:/usr/share/java/log4j-1.2.jar:/usr/share/java/xercesImpl.jar:/usr/share/java/xmlParserAPIs.jar:/usr/share/java/netty.jar:/usr/share/java/slf4j-api.jar:/usr/share/java/slf4j-log4j12.jar:/usr/share/java/zookeeper.jar
2018-08-14 14:53:46,179 - INFO  [main:Environment@100] - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
2018-08-14 14:53:46,179 - INFO  [main:Environment@100] - Server environment:java.io.tmpdir=/tmp
2018-08-14 14:53:46,179 - INFO  [main:Environment@100] - Server environment:java.compiler=<NA>
2018-08-14 14:53:46,192 - INFO  [main:Environment@100] - Server environment:os.name=Linux
2018-08-14 14:53:46,192 - INFO  [main:Environment@100] - Server environment:os.arch=amd64
2018-08-14 14:53:46,193 - INFO  [main:Environment@100] - Server environment:os.version=4.9.0-4-amd64
2018-08-14 14:53:46,194 - INFO  [main:Environment@100] - Server environment:user.name=zookeeper
2018-08-14 14:53:46,194 - INFO  [main:Environment@100] - Server environment:user.home=/var/lib/zookeeper
2018-08-14 14:53:46,194 - INFO  [main:Environment@100] - Server environment:user.dir=/
2018-08-14 14:53:46,211 - INFO  [main:ZooKeeperServer@815] - tickTime set to 2000
2018-08-14 14:53:46,212 - INFO  [main:ZooKeeperServer@824] - minSessionTimeout set to -1
2018-08-14 14:53:46,212 - INFO  [main:ZooKeeperServer@833] - maxSessionTimeout set to -1
2018-08-14 14:53:46,242 - INFO  [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:2181
2018-08-14 14:53:46,342 - ERROR [main:ZooKeeperServerMain@64] - Unexpected exception, exiting abnormally
java.io.EOFException
	at java.io.DataInputStream.readInt(DataInputStream.java:392)
	at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
	at org.apache.zookeeper.server.persistence.FileHeader.deserialize(FileHeader.java:64)
	at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.inStreamCreated(FileTxnLog.java:585)
	at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.createInputArchive(FileTxnLog.java:604)
	at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.goToNextLog(FileTxnLog.java:570)
	at org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.next(FileTxnLog.java:652)
	at org.apache.zookeeper.server.persistence.FileTxnSnapLog.restore(FileTxnSnapLog.java:158)
	at org.apache.zookeeper.server.ZKDatabase.loadDataBase(ZKDatabase.java:223)
	at org.apache.zookeeper.server.ZooKeeperServer.loadData(ZooKeeperServer.java:283)
	at org.apache.zookeeper.server.ZooKeeperServer.startdata(ZooKeeperServer.java:410)
	at org.apache.zookeeper.server.NIOServerCnxnFactory.startup(NIOServerCnxnFactory.java:118)
	at org.apache.zookeeper.server.ZooKeeperServerMain.runFromConfig(ZooKeeperServerMain.java:119)
	at org.apache.zookeeper.server.ZooKeeperServerMain.initializeAndRun(ZooKeeperServerMain.java:87)
	at org.apache.zookeeper.server.ZooKeeperServerMain.main(ZooKeeperServerMain.java:53)
	at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:116)
	at org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:78)
Reedy updated the task description. (Show Details)Aug 15 2018, 3:59 PM
Reedy removed a subscriber: Reedy.

Really hard to tell what is going on here. The easiest thing to do would be to create a new MW Vagrant instance from scratch and start over.

Alternatively, you might be able to just wipe Zookeeper and Kafka data, and then start them both back up. Something like:

sudo service kafka stop
sudo service zookeeper stop
sudo rm -rf /var/lib/zookeeper/*
sudo rm -rf /var/lib/kafka/* /var/lib/kafka/.*
sudo service zookeeper start # check that zookeeper actually starts up fine
sudo service kafka start # check that kafka starts up fine

@Ottomata: That still leaves zookeeper dying with the same exception as in my previous message, unfortunately.

I can try making a new VM and seeing if the problem persists, though I'm on terrible wifi right now and that's not a good place to do that.

mforns assigned this task to elukey.Mar 11 2019, 3:54 PM
mforns added a subscriber: mforns.

We have not been able to reproduce this issue. But maybe @elukey has an idea of how to solve?

elukey added a comment.EditedMar 11 2019, 4:02 PM

@DLynch did you manage to solve the issue? From the description I thought it was a problem with logs storage, but it seems more a corrupted zookeeper environment that just needs to be created. I am inclined to close, please re-open if the problem still persists :)

elukey closed this task as Resolved.Mar 11 2019, 4:03 PM

@elukey No, nothing to fix it. Though it had, looking at it just now, switched into wildly spamming this into the log instead:

Mar  7 20:50:40 vagrant kafka-server-start[1228]: [2019-03-07 20:50:40,671] ERROR [Controller id=0, targetBrokerId=0] Connection to node 0 failed authentication due to: SSL handshake failed (org.apache.kafka.clients.NetworkClient)
DLynch reopened this task as Open.Jul 15 2020, 5:01 PM

This is still happening, and is causing issues with our team's prototype-testing server.

In T238837, I'd like to make the default vagrant EventLogging setup not require Kafka. Hopefully that will at least work around this problem for folks that don't need the full Kafka pipeline just for their dev environment.

Makes sense to me. 👍🏻

Change 627910 had a related patch set uploaded (by Ottomata; owner: Ottomata):
[mediawiki/vagrant@master] Use eventgate-wikimedia-dev by default

https://gerrit.wikimedia.org/r/627910

Change 627910 merged by jenkins-bot:
[mediawiki/vagrant@master] Use eventgate-wikimedia-dev by default

https://gerrit.wikimedia.org/r/627910