Steven Schlansker created KAFKA-3921:
----------------------------------------
Summary: Periodic refresh of metadata causes spurious log messages
Key: KAFKA-3921
URL: https://issues.apache.org/jira/browse/KAFKA-3921
Project: Kafka
Issue Type: Improvement
Components: clients
Affects Versions: 0.9.0.1
Reporter: Steven Schlansker
Kafka cluster metadata has a configurable expiry period. (I don't understand
why this is -- cluster updates can happen at any time, and we have to pick
those up quicker than every 10 minutes? But this ticket isn't about that.)
When this interval expires, the ClientUtils class spins up a SyncProducer,
which sends a special message to retrieve metadata. The producer is then
closed immediately after processing this message.
This causes the SyncProducer to log both a connection open and close at INFO
level:
{code}
2016-06-30T17:50:19.408Z INFO <> [ProducerSendThread-central-buzzsaw-1-myhost]
kafka.client.ClientUtils$ - Fetching metadata from broker
BrokerEndPoint(2,broker-3.mycorp.com,9092) with correlation id 17188 for 1
topic(s) Set(logstash)
2016-06-30T17:50:19.410Z INFO <> [ProducerSendThread-central-buzzsaw-1-myhost]
kafka.producer.SyncProducer - Connected to broker-3.mycorp.com:9092 for
producing
2016-06-30T17:50:19.411Z INFO <> [ProducerSendThread-central-buzzsaw-1-myhost]
kafka.producer.SyncProducer - Disconnecting from broker-3.mycorp.com:9092
2016-06-30T17:50:19.411Z INFO <> [ProducerSendThread-central-buzzsaw-1-myhost]
kafka.producer.SyncProducer - Disconnecting from broker-14.mycorp.com:9092
2016-06-30T17:50:19.411Z INFO <> [ProducerSendThread-central-buzzsaw-1-myhost]
kafka.producer.SyncProducer - Disconnecting from
broker-logkafka-13.mycorp.com:9092
2016-06-30T17:50:19.411Z INFO <> [ProducerSendThread-central-buzzsaw-1-myhost]
kafka.producer.SyncProducer - Disconnecting from broker-12.mycorp.com:9092
2016-06-30T17:50:19.413Z INFO <> [ProducerSendThread-central-buzzsaw-1-myhost]
kafka.producer.SyncProducer - Connected to broker-12.mycorp.com:9092 for
producing
{code}
When you are reading the logs, this appears periodically. We've had more than
one administrator then think that the cluster is unhealthy, and client
connections are getting dropped -- it's disconnecting from the broker so
frequently! What is wrong??? But in reality, it is just this harmless /
expected metadata update.
Can we tweak the log levels so that the periodic background refresh does not
log unless something goes wrong? The log messages are misleading and easy to
misinterpret. I had to read the code pretty thoroughly to convince myself that
these messages are actually harmless.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
