Impact of logging on Kafka through put

[Prashant Prakash <pr...@gmail.com>]

Dear Kafka Users,

We are using kafka-2.8.0-0.8.8 in our application development. The
application is running with two brokers each having one partition.

We are using high level api to send message over async producer. While
testing through put of our application we have observed that  more than 60
% of the time was spent in getPartitionListForTopic method of
DefaultEventHandler class.

We have set topic.metadata.refresh.interval.ms=-1. The method
 (getPartitionListForTopic ) is invoked per message and primarily returns
the broker-partition info for the topic from topicPartitionInfo map apart
from logging.

To narrow down time intensive process we  had explicitly set log level as
* log4j.logger.kafka.producer.async.DefaultEventHandler=OFF
* log4j.logger.kafka.producer.BrokerPartitionInfo=OFF

The above change resulted in 3 times increase in producer through put. We
have verified the above behavior consistently.

Has similar behavior been observed earlier ?
If not then any suggestion, areas to look upon to drill down the issue.

We are thinking of setting the log level for the mentioned class as ERROR.

Please share views, solutions.

Thank you very much.

Best regards
Prashant

Re: Impact of logging on Kafka through put

[Prashant Prakash <pr...@gmail.com>]

On further investigation we found that similar issue is already filed under
https://issues.apache.org/jira/browse/KAFKA-1351

To re validate we explicitly commented per message logs
in BrokerPartitionInfo.scala and DefaultEventHandler.scala.

The disabling of logs resulted in 5 times increase in producer through put.

Best regards
Prashant


On Wed, Oct 15, 2014 at 12:18 AM, Prashant Prakash <pr...@gmail.com>
wrote:

> Dear Kafka Users,
>
> We are using kafka-2.8.0-0.8.8 in our application development. The
> application is running with two brokers each having one partition.
>
> We are using high level api to send message over async producer. While
> testing through put of our application we have observed that  more than 60
> % of the time was spent in getPartitionListForTopic method of
> DefaultEventHandler class.
>
> We have set topic.metadata.refresh.interval.ms=-1. The method
>  (getPartitionListForTopic ) is invoked per message and primarily returns
> the broker-partition info for the topic from topicPartitionInfo map apart
> from logging.
>
> To narrow down time intensive process we  had explicitly set log level as
> * log4j.logger.kafka.producer.async.DefaultEventHandler=OFF
> * log4j.logger.kafka.producer.BrokerPartitionInfo=OFF
>
> The above change resulted in 3 times increase in producer through put. We
> have verified the above behavior consistently.
>
> Has similar behavior been observed earlier ?
> If not then any suggestion, areas to look upon to drill down the issue.
>
> We are thinking of setting the log level for the mentioned class as ERROR.
>
> Please share views, solutions.
>
> Thank you very much.
>
> Best regards
> Prashant
>
>
>
>
>
>
>