Create lazy messages in log4j2

Question

I have this code:

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
public class Test {
  private static final Logger logger = LogManager.getLogger();
  public static void main (String[] args) {
    logger.info("Text: {}", getText());
  }
  static String getText() {
    // Expensive action using IO
    return "";
  }
}

In my log4j2.json, the logger is set to ERROR.

I want that when it is not needed, getText() is not called at all. For that, I used the message API and I wrote the following instead:

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.message.Message;
public class Test {
  private static final Logger logger = LogManager.getLogger();
  public static void main (String[] args) {
    logger.info(new TextMessage());
  }
  static String getText() {
    // Expensive action using IO
    return "";
  }
  static class TextMessage implements Message {
    @Override public String getFormat() { return null; }
    @Override public String getFormattedMessage() {
        return String.format("text: %s", getText());
    }
    @Override public Object[] getParameters() { return null; }
    @Override public Throwable getThrowable() { return null; }
  }
}

I have two issues with this code.

1. I cannot use the {} usually used for the logging.
2. It is extremely verbose.

I checked in the javadoc for any Message that I could use in Java 8's lambda expressions (meaning, only one abstract method), but there is none.

I've thought about creating a ToStringable interface to be used as the following.

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
public class Test {
  private static final Logger logger = LogManager.getLogger();
  public static void main (String[] args) {
    logger.info("Text: {}", new ToStringable() { public String toString() { return getText();}});
  }
  static String getText() {
    // Expensive action using IO
    return "";
  }
}
interface ToStringable { @Override String toString(); }

This gets the job done, but it's barely readable and I cannot use Java 8's lambda on this (see below, note this code fails to compile).

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
public class Test {
  private static Logger logger = LogManager.getLogger();
  public static void main (String[] args) {
    logger.info("Text: {}", () -> getText());
  }
  static String getText() {
    // Expensive action using IO
    return "";
  }
}
interface ToStringable {@Override String toString(); }

Finally, only the good old if (logger.isXxxxEnabled()) { logger.xxxx(...) } solved the issue reliably, but what's the point of using a modern, lazy logger?

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
public class Test {
  private static final Logger logger = LogManager.getLogger();
  public static void main (String[] args) {
    if (logger.isInfoEnabled()) {
      logger.info("Text: {}", getText());
    }
  }
  static String getText() {
    // Expensive action using IO
    return "";
  }
}

So did anyone encounter this issue and if yes, how was it solved?

Final words: the 3 first code snippets are short, self-contained, correct examples. This means that they're only here to show the problem. Don't think outside of the problem please (meaning: don't tell me to be pragmatic and just let go).

Answer 1

There are two issues with your ToStringable approach.

1. When you converted the inner class to a lambda expression you removed any hint for the compiler that your lambda expression ought to implement ToStringable. The receiver type is Object (or well, whatever the compiler might attempt when trying one of the overloaded methods of the log4j API). The lambda expression needs a target type, in other words, if you don’t assign it to an appropriately typed variable and the parameter type isn’t suitable, you have to insert a type cast like (ToStringable) ()->""
2. But this doesn’t help here as you are attempting to override a method declared in java.lang.Object. Lambda expressions can’t override methods inherited from java.lang.Object ¹.

In order to solve this you need a helper method using the good old inner class approach for overriding Object.toString() delegating to another interface which can be implemented via lambda expression:

import java.util.function.Supplier;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class Log4jTest {

  private static final Logger logger = LogManager.getLogger();
  public static void main (String[] args) {
    logger.info("Text: {}", lazy( ()->getText() ));
    logger.error("Text: {}", lazy(Log4jTest::getText));
  }
  // reusable helper method
  static Object lazy(Supplier<String> s) {
    return new Object() {
      @Override
      public String toString() {
          return s.get();
      }
    };
  }
  static String getText() {
    System.out.println("very long computation");
    return "";
  }
}

This example shows both, using a lambda expression and a method reference but of course, the difference in behavior stems from the different logging level. As long as log4j doesn’t offer a functional interface input like the other API, the helper method with the one inner class is unavoidable. But you need to implement it only once while all callers can use lambda expressions.

Answer 2

UPDATE (2015 Aug 5)

Consider voting for this ticket LOG4J2-599 to bring support for lambda expressions to Log4j 2.

---

UPDATE (2015 Aug 10)

The next version of Log4J, 2.4, will have lambda support. Example usage:

// log message is not constructed if DEBUG level is not enabled
logger.debug("Result of some expensive operation is {}", () -> someLongRunningOperation());

---

The question has already been answered, this is just some extra advice in case you are planning to use this with async loggers or an async appender:

• You mention that creating the message result is an expensive operation. I assume that you want to use async loggers/appenders to improve your app's throughput and/or response time. Makes sense. Be aware that if creating the message result is really expensive then (depending on how much you are logging) your queue may fill up; once that happens you are essentially logging synchronously again. You can tune the queue size to help you deal with bursts, but if the sustained logging rate is very high you may run into this problem. Log4j2 includes JMX MBeans (1, 2) you can use to query how full the queue is.
• The output log result will reflect the value of the message at the time the background I/O thread called Message.getFormattedMessage, not the value of the message at the time your application thread called Logger.info. If many lazy messages are logged, the time gap between these two events may grow. Also be aware that your message object needs to be thread-safe. You probably know this already, but I thought it was worth pointing out.

I hope this is useful.