kafka-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Steven Schlansker (JIRA)" <j...@apache.org>
Subject [jira] [Created] (KAFKA-3921) Periodic refresh of metadata causes spurious log messages
Date Thu, 30 Jun 2016 18:03:10 GMT
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)

Mime
View raw message