Java 8 Deferred Invocation with Java Util Logging

In the blog post Better Performing Non-Logging Logger Calls in Log4j2, I looked at approaches one can use in Log4j 2 to reduce or avoid invocation of methods in log statements that, based on the specified log level, are not actually logged at all. As part of this discussion, I covered Log4j 2's support for Java 8-based deferred execution using lambda expressions. In this post, I demonstrate using the built-in java.util.logging (JUL) support for deferred execution of methods in log statements using lambda expressions in a similar way to that supported by Log4j 2.

The java.util.logging.Logger class-level Javadoc documentation describes JUL's support for deferred execution:

A set of methods alternatively take a "msgSupplier" instead of a "msg" argument. These methods take a Supplier function which is invoked to construct the desired log message only when the message actually is to be logged based on the effective log level thus eliminating unnecessary message construction.

Browsing the public API for java.util.logging.Logger provides a quick overview of the methods referenced in that comment that use a supplier to allow for deferral of method invocation until it is actually known that the log needs to be made. The code.util.logging.Logger methods that accept an instance of the built-in functional interface java.util.function.Supplier as an argument. For example, the next screen snapshot captures a small portion of the HTML rendered Javadoc with some of the methods that accept a Supplier.

I like to use javap to easily view a Java class's public API. This can be done in this case by executing the command javap -classpath rt.jar java.util.logging.Logger from the $JAVA_HOME/jre/lib directory (assuming you've configured the JAVA_HOME environment variable). The next screen snapshot depicts the execution of this command and the first portion of the results. That screen snapshot is followed by text version of the output with the uses of Supplier emphasized.

Compiled from "Logger.java"
public class java.util.logging.Logger {
  static final java.lang.String SYSTEM_LOGGER_RB_NAME;
  public static final java.lang.String GLOBAL_LOGGER_NAME;
  public static final java.util.logging.Logger global;
  static final boolean $assertionsDisabled;
  public static final java.util.logging.Logger getGlobal();
  protected java.util.logging.Logger(java.lang.String, java.lang.String);
  java.util.logging.Logger(java.lang.String, java.lang.String, java.lang.Class<?>, java.util.logging.LogManager, boolean);
  void setLogManager(java.util.logging.LogManager);
  public static java.util.logging.Logger getLogger(java.lang.String);
  public static java.util.logging.Logger getLogger(java.lang.String, java.lang.String);
  static java.util.logging.Logger getPlatformLogger(java.lang.String);
  public static java.util.logging.Logger getAnonymousLogger();
  public static java.util.logging.Logger getAnonymousLogger(java.lang.String);
  public java.util.ResourceBundle getResourceBundle();
  public java.lang.String getResourceBundleName();
  public void setFilter(java.util.logging.Filter) throws java.lang.SecurityException;
  public java.util.logging.Filter getFilter();
  public void log(java.util.logging.LogRecord);
  public void log(java.util.logging.Level, java.lang.String);
  public void log(java.util.logging.Level, java.util.function.Supplier<java.lang.String>);
  public void log(java.util.logging.Level, java.lang.String, java.lang.Object);
  public void log(java.util.logging.Level, java.lang.String, java.lang.Object[]);
  public void log(java.util.logging.Level, java.lang.String, java.lang.Throwable);
  public void log(java.util.logging.Level, java.lang.Throwable, java.util.function.Supplier<java.lang.String>);
  public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String);
  public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.util.function.Supplier<java.lang.String>);
  public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.Object);
  public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.Object[]);
  public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.Throwable);
  public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.Throwable, java.util.function.Supplier<java.lang.String>);
  public void logrb(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.String);
  public void logrb(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.String, java.lang.Object);
  public void logrb(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.String, java.lang.Object[]);
  public void logrb(java.util.logging.Level, java.lang.String, java.lang.String, java.util.ResourceBundle, java.lang.String, java.lang.Object...);
  public void logrb(java.util.logging.Level, java.lang.String, java.lang.String, java.lang.String, java.lang.String, java.lang.Throwable);
  public void logrb(java.util.logging.Level, java.lang.String, java.lang.String, java.util.ResourceBundle, java.lang.String, java.lang.Throwable);
  public void entering(java.lang.String, java.lang.String);
  public void entering(java.lang.String, java.lang.String, java.lang.Object);
  public void entering(java.lang.String, java.lang.String, java.lang.Object[]);
  public void exiting(java.lang.String, java.lang.String);
  public void exiting(java.lang.String, java.lang.String, java.lang.Object);
  public void throwing(java.lang.String, java.lang.String, java.lang.Throwable);
  public void severe(java.lang.String);
  public void warning(java.lang.String);
  public void info(java.lang.String);
  public void config(java.lang.String);
  public void fine(java.lang.String);
  public void finer(java.lang.String);
  public void finest(java.lang.String);
  public void severe(java.util.function.Supplier<java.lang.String>);
  public void warning(java.util.function.Supplier<java.lang.String>);
  public void info(java.util.function.Supplier<java.lang.String>);
  public void config(java.util.function.Supplier<java.lang.String>);
  public void fine(java.util.function.Supplier<java.lang.String>);
  public void finer(java.util.function.Supplier<java.lang.String>);
  public void finest(java.util.function.Supplier<java.lang.String>);
  public void setLevel(java.util.logging.Level) throws java.lang.SecurityException;
  final boolean isLevelInitialized();
  public java.util.logging.Level getLevel();
  public boolean isLoggable(java.util.logging.Level);
  public java.lang.String getName();
  public void addHandler(java.util.logging.Handler) throws java.lang.SecurityException;
  public void removeHandler(java.util.logging.Handler) throws java.lang.SecurityException;
  public java.util.logging.Handler[] getHandlers();
  java.util.logging.Handler[] accessCheckedHandlers();
  public void setUseParentHandlers(boolean);
  public boolean getUseParentHandlers();
  public void setResourceBundle(java.util.ResourceBundle);
  public java.util.logging.Logger getParent();
  public void setParent(java.util.logging.Logger);
  final void removeChildLogger(java.util.logging.LogManager$LoggerWeakRef);
  static java.util.logging.Logger$LoggerBundle access$000();
  static java.util.logging.Logger$LoggerBundle access$100();
  static {};
}

We can see from the public API for java.util.logging.Logger that there are overloaded methods for "precise logging" (logp methods that accept two Strings for explicitly specified class and method names) and for "regular logging" that accept instances of Supplier. These methods allow for the supplier to only be processed if the logging level is set to a level specific enough for the log statement to be written.

Here is a list of the current java.util.logging.Logger methods accepting a Supplier instance:

• Regular, Specific-Level Logging Methods
  • public void severe(java.util.function.Supplier<java.lang.String>);
  • public void warning(java.util.function.Supplier<java.lang.String>);
  • public void info(java.util.function.Supplier<java.lang.String>);
  • public void config(java.util.function.Supplier<java.lang.String>);
  • public void fine(java.util.function.Supplier<java.lang.String>);
  • public void finer(java.util.function.Supplier<java.lang.String>);
  • public void finest(java.util.function.Supplier<java.lang.String>);
• Regular, General Logging Methods Requiring Specification of Log Level
  • public void log(java.util.logging.Level, java.util.function.Supplier<java.lang.String>);
  • public void log(java.util.logging.Level, java.lang.Throwable, java.util.function.Supplier<java.lang.String>);
• "Precise" Logging Method
  • public void logp(java.util.logging.Level, java.lang.String, java.lang.String, java.util.function.Supplier<java.lang.String>);

Keeping in mind that the precise logging method (with name logp) accepts its String arguments for class and method names, one of the most significant differences between JUL's deferred invocation logging API from Log4j 2's implementation can be observed: the JUL implementation does not allow for a "message" string to be provided as a separate (additional) parameter to its logging methods.

In my previous blog post, I demonstrated use of Log4j 2's org.apache.logging.log4j.Logger.debug(String message, Supplier<?>... paramSuppliers) method that accepts a message String in addition to the deferred execution of a provided Supplier. There are similar methods provided in Log4j 2's org.apache.logging.log4j.Logger for other specific log levels (error, fatal, info, trace, and warn) and for the general logging with explicit specification of log level. The additional flexibility to easily provide context via a separate String from the Supplier is a nice one to have. It's also worth noting that Log4j 2's Logger also supports various log methods that accept only a Supplier (without any context message String) similar to the methods java.util.logging.Logger provides.

In the blog post Top Five Reasons to Try Java 8, John Shepard writes that "now that Functions can be passed into (and returned) from methods, log.isLogLevelEnabled and similar methods no longer needs to be spattered across the code base." He then provides a simple code listing that demonstrates how to provide String context via this API when an individual String argument for message context is not part of the method's signature. My example at the end of this post will be similar.

As I discussed in my post Better Performing Non-Logging Logger Calls in Log4j2, deferred execution powered by Java lambda expressions allows developers to remove logging guards from their code by deferring both implicit and explicit method calls on passed-in objects until the lambda expression is resolved. This is never done if the logging level the software is running at is less specific than the specific log level of the message. In other words, code can be converted from the next shown code listing to be like the smaller code listing that follows it.

if (logger.isLoggable(Level.FINE))
{
   logger.fine("GUARDED: " + slow);
}
if (logger.isLoggable(Level.FINE))
{
   logger.fine(expensiveOperation());
}

logger.fine(() -> "LAMBDA: " + slow);
logger.fine(this::expensiveOperation);

Although many things in software development are really matters of taste and opinion, it's difficult to imagine many arguments in favor of the earlier, more verbose code. Despite what some assert, less code is NOT always more readable to everyone. However, in this case, I believe that there are very few developers who would argue that the more verbose code is in anyway better than the Java 8 version.