Log4j: is it synchronized for multithreaded calls?

Question

We are running into an interesting issue that we noticed while doing stress testing of our system. We are using log4j (in JBOSS) very heavily for our logging. Here is a naive example of some logging we ave

void someFunction()
{
Log.info("entered some function");
...

Log.info("existed some function");
}

Now the interesting thing we noticed is that if we launch 100 threads against this function; the Log.info() calls is blocking per thread.. meaning thread 2 is waiting for thread1 to finish the "Log.info" call. In case of Thread 100; it ends up waiting quite a long time.. We are using a native file logger.

Is this a known issue?

Answer 1

Log4J has to be synchronized, otherwise you would see interleaved and garbled log messages in your file. But at least in Logback only appenders are synchronized, not the whole logging message (so computing effective log level, log message, etc. is multi-threaded).

However even if synchronization was removed, I/O would be the bottleneck since it is inherently single-threaded. Thus consider reducing the amount of logging, since it is the file access that is slow, not Log4J.

You may also be interested in AsyncAppender to queue logging messages in a single, different thread.