Java Lambda Expression and Logging

Question

I was reading the new features of Log4j2 and there's a feature that enables

"Java 8 lambda support for lazy logging"

And it gives two examples

The first one is the bad practice

// pre-Java 8 style optimization: explicitly check the log level
// to make sure the expensiveOperation() method is only called if necessary
 if (logger.isTraceEnabled()) {
  logger.trace("Some long-running operation returned {}", expensiveOperation());
 }

And the second one is the good practice

// Java-8 style optimization: no need to explicitly check the log level:
// the lambda expression is not evaluated if the TRACE level is not enabled
logger.trace("Some long-running operation returned {}", () -> expensiveOperation());

Where is being made the checking if the requested log level is enabled ? "logger.isTraceEnabled()" ?

Answer 1

Where is being made the checking if the requested log level is enabled ?

Inside the logger.trace() method.

The trick here however is in the way you pass the argument. Pre-java8 style computed the value at the time of calling logger.trace.

logger.trace(..., expensiveOperation());

Java 8 style uses a Supplier

logger.trace( ..., () -> expensiveOperation());

So the expensiveOperation() is called only when requested - inside the trace method.

Have a look at implementation of java.util.logging.Logger.log():

public void log(Level level, Supplier<String> msgSupplier) {
    if (!isLoggable(level)) {
        return;
    }
    LogRecord lr = new LogRecord(level, msgSupplier.get()); // <-- here is the expensive computation
    doLog(lr);
}

Answer 2

The trace method (or any other logging method for that sake) already checks logging level internally. Checking it in the caller too is an optimization to avoid calculating expensiveOperation(). With Java 8's new syntax, we don't pass the calculated value of expensiveOperation(), but a lambda that invokes it only if needed.

Note that although log4j didn't implement it, you could, in theory, have the same behavior without the fancy Java 8 syntax by defining an interface for a value provider, and have the logging method call it:

// Interface definition
public interface ValueProvider {
    String getValue();
}

// Calling it from the main code with an anonymous implementation:
logger.trace("Some long-running operation returned {}",
             new ValueProvider() {
                 public String getValue() {
                     return expensiveOperation();
                 }
             });