Ralph, you are right, I am measuring the time before control is returned to the application.
But that is exactly the selling point, because that is what log4j users care about. (At least I hope it is not just me
150 nanos! with the semantics of immediateFlush! (because FastFileAppender flushes to disk at the end of each batch)
That would put Log4j2 in a whole different performance category than Log4j-1.x or LogBack, wouldn't you agree?
As long as logging throughput is fast enough that the buffers don't fill up so that any slowness in the actually logging does not impact the application, the actual speed of writing events to disk is less important.
Wrapping either FileAppender or FastFileAppender in a AsyncAppender actually makes things slower, at least on Solaris.
For reference, below are the numbers for the same tests with AsyncAppender, measured on Solaris-10 64 bit, JDK 1.7.0_06,
8 cores Xeon X5570 CPU @ 2.93 GHz with hyperthreading switched on
SL = Standard (synchronized) Logger
AA/SA = AsynchAppender with Standard File Appender with BufferedIO=true
AA/FA = AsynchAppender with Fast File Appender
default buffer = 128
large buffer = 262144 (same buffer size as ringbuffer used in disruptor)
IF = ImmediateFlush=true
SL + (default buffer AA/SA): 17168 nanos (average of 18480, 13778, 17573, 17730, 18279)
SL + (default buffer AA/FA): 16467 nanos (average of 16991, 17143, 17319, 13646, 17238)
SL + (large buffer AA/SA): 17541 nanos (average of 17734, 17852, 17756, 16918, 17445)
SL + (large buffer AA/FA): 17117 nanos (average of 17136, 17522, 16680, 17147, 17103)
SL + (default buffer AA/SA) + IF: 16703 nanos (average of 17783, 17863, 12868, 18265, 16736)
SL + (default buffer AA/FA) + IF: 13983 nanos (average of 18063, 11346, 13634, 13081, 13791)
SL + (large buffer AA/SA) + IF: 17860 nanos (average of 17821, 17664, 17906, 18070, 17840)
SL + (large buffer AA/FA) + IF: 17641 nanos (average of 17739, 17794, 16974, 17871, 17827)
If you want to verify these results in your environment, you can unzip the attachment and
run the AsyncLoggerPerfTest.bat and SyncLoggerPerfTest.bat scripts.
They should work out of the box. Each script runs a single test with the log4j2.xml config in the bin/ folder.