Log4j 2 API
Log Builder
Log4j has traditionally been used with logging statements like
logger.error("Unable to process request due to {}", code, exception);
logger.atError().withThrowable(exception).log("Unable to process request due to {}", code);
With this syntax it is clear that the exception is to be treated as a Throwable by Log4j.
The Logger class now returns a LogBuilder when any of the atTrace, atDebug, atInfo, atWarn, atError, atFatal, always, or atLevel(Level) methods are called. The logBuilder then allows a Marker, Throwable, and/or location to be added to the event before it is logged. A call to the log method always causes the log event to be finalized and sent.
A logging statement with a Marker, Throwable, and location would look like:
logger.atInfo().withMarker(marker).withLocation().withThrowable(exception).log("Login for user {} failed", userId);
Providing the location method on the LogBuilder provides two distinct advantages:
- Logging wrappers can use it to provide the location information to be used by Log4j.
- The overhead of capturing location information when using the location method with no parameters is much better than having to calculate the location information when it is needed. Log4j can simply ask for the stack trace entry at a fixed index instead of having to walk the stack trace to determine the calling class. Of course, if the location information will not be used by the layout this will result in slower performance.
Location Performance
The table below shows some of the results from the FileAppenderBenchmark and FileAppenderWithLocationBenchmark classes in the log4j-perf project when configured to use 4 threads. The results show that lazily including the location information is about 8 times slower than not including location information. While using the withLocation method of LogBuilder is about 3 times faster than lazily calculating the location information it is still about 2.5 times slower than not including location information.
The tests were run on a 2018 MacBook Pro with a 2.9 GHz Intel Core i9 processor with 6 cores, 32 GB of memory and 1 TB of SSD storage on Java 11 using Log4j 2.13.0 and Logback 1.2.3.
Test | Print Location Info | No Location Info Printed |
---|---|---|
Log4j2 File | 191,509.724 ± 11339.978 ops/s | 1,407,329.130 ± 22595.997 ops/s |
Log4j2 Log Builder withLocation() | 469,200.684 ± 50025.985 ops/s | 577,127.463 ± 11464.342 ops/s |
Logback File | 159,116.538 ± 1884.969 ops/s | 1,240,438.384 ± 76619.873 ops/s |
As expected, when using LogBuilder with a call to the withLocation() method logging is much faster when location information is used in the output but significantly slower when it is not.
Note: Running the tests at various times provides varying results. Although some results have been as much as 10% higher all results are generally affected similarly so the comparisons between them stay the same.