I'm having performance issues using log4j2 (2.5) in combination with Kafka (0.10.1.0). When I enable Kafka in the log4j2.xml file, my application slows down to a crawl, whilst only outputting around 200KB/s of events to the Kafka broker. This is orders of magnitude lower than that what Kafka is supposed to achieve (https://engineering.linkedin.com/kafka/benchmarking-apache-kafka-2-million-writes-second-three-cheap-machines).
Here is the relevant part of my log4j2.xml config file:
<Kafka name="KafkaAll" topic="all">
<PatternLayout pattern="%date %message" />
<Property name="bootstrap.servers">localhost:9092</Property>
<Property name="buffer.memory">67108864</Property>
<Property name="batch.size">8196</Property>
<Property name="acks">1</Property>
</Kafka>
After running some tests I've been able to pin down the problem and found out that the ProducerPerformance test shipped with Kafka does achieve decent performance. Its performance is around 5MB/s, with similar sized messages of 100 bytes. After extensive testing, I found out that the difference lies not in the configuration, but in the way the calls are implemented. The log4j2 KafkaAppender uses the KafkaManager class to write log to Kafka:
public void send(final byte[] msg) throws ExecutionException, InterruptedException, TimeoutException {
if (producer != null) {
producer.send(new ProducerRecord<byte[], byte[]>(topic, msg)).get(timeoutMillis, TimeUnit.MILLISECONDS);
}
}
The performance problem is caused by the call to the "get" method, which blocks until the send has completed. Funny enough, there is a log4j appender included with Kafka that does take this issue into account:
Future<RecordMetadata> response = producer.send(new ProducerRecord<byte[], byte[]>(topic, message.getBytes()));
if (syncSend) {
try {
response.get();
} catch (InterruptedException ex) {
throw new RuntimeException(ex);
} catch (ExecutionException ex) {
throw new RuntimeException(ex);
}
}
In other words, when syncSend is set to false, the call to send returns immediately. This "syncSend" property is however nowhere to be found in the log4j2 implementation of the KafkaAppender.
I've tried making calls asynchronous through other means, such as using the AsyncAppender shipped with log4j2 and setting the acks property to 0 instead of 1. However, none of the settings achieve the performance gain by not waiting for the send to complete. I've also tried to use the log4j appender shipped with Kafka, but I did not manage to get it to work with log4j2 (and I want to stick with log4j2).
So, finally, I have decided to fork the KafkaAppender shipped with log4j2 and remove the blocking part of the call. This works, but of course I'd rather be using of-the-shelf packages.
Is there anyone who also ran into this problem? How did you solve the issue? Is there an easier way without changing code?