Logging performance when logging is turned off.
When logging is turned off entirely or just for a set of Levels, the cost of a log request consists of
two method invocations plus an integer comparison. On a 2.53 GHz Intel Core 2 Duo MacBook Pro
calling isDebugEnabled 10 million times produces an average result in nanoseconds of:
Log4j: 4
Logback: 5
Log4j 2: 3
The numbers above will vary slightly from run to run so the only conclusion that should be
drawn is that all 3 frameworks perform similarly on this task.
However, The method invocation involves the "hidden" cost of parameter construction.
For example,
logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
incurs the cost of constructing the message parameter, i.e. converting both integer
i and entry[i] to a String, and concatenating intermediate strings,
regardless of whether the message will be logged or not.
This cost of parameter construction can be quite high and it
depends on the size of the parameters involved.
A comparison run on the same hardware as above yields:
Log4j: 188
Logback: 183
Log4j 2: 188
Again, no conclusion should be drawn regarding relative differences between the frameworks on
this task, but it should be obvious that it is considerably more expensive than simply testing
the level.
The best approach to avoid the cost of parameter construction is to use Log4j 2's formatting
capabilities. For example, instead of the above write:
logger.debug("Entry number: {} is {}", i, entry[i]);
Using this approach, a comparison run again on the same hardware produces:
Log4j: Not supported
Logback: 9
Log4j 2: 4
These results show that the difference in performance between the call to isDebugEnabled and
logger.debug is barely discernable.
In some circumstances one of the parameters to logger.debug will be a costly method call that
should be avoided if debugging is disabled. In those cases write:
if(logger.isDebugEnabled() {
logger.debug("Entry number: " + i + " is " + entry[i].toString());
}
This will not incur the cost of whatever the toString() method needs to do if debugging is disabled.
On the other hand, if the logger is enabled for the debug level, it will incur twice the cost of
evaluating whether the logger is enabled or not: once
in isDebugEnabled and once in debug. This is an insignificant
overhead because evaluating a logger takes about 1% of the time it takes to actually log.
Certain users resort to preprocessing or compile-time
techniques to compile out all log statements. This leads to perfect
performance efficiency with respect to logging. However, since the
resulting application binary does not contain any log statements,
logging cannot be turned on for that binary. This seems to be
a disproportionate price to pay in exchange for a small performance
gain.
Actually outputting log messages
This is the cost of formatting the log output and sending it to its target destination. Here again,
a serious effort was made to make layouts (formatters) perform as quickly as possible. The same
is true for appenders. One of the fundamental tenants of Log4j 2 is to use immutable objects whenever
possible and to lock at the lowest granularity possible. However, the cost of actually formatting and
delivering log events will never be insignificant. For example, the results of writing to a simple log
file using the same format using Log4j, Logback and Log4j 2 are:
Log4j: 1651
Logback: 1419
Log4j 2.0: 1542
As with many of the other results on this page the differences between the frameworks above should be
considered insignificant. The values will change somewhat on each execution and changing the order the
frameworks are tested or adding calls to System.gc() between the tests can cause a variation in the
reported times. However, these results show that actually writing out the events can be at least 1000
times more expensive than when they are disabled, so it is always recommended to take advantage of
Log4j 2's fine-grained filtering capabilities.