04 March 2016

Why logging frameworks did not make use of Java 8 like JUL did

1)
In scala the language, there's three types of value definition; regular variables that are initialized once reached by the execution environment like:

val x: Int = getXValueFromDatabase()

the function getXValueFromDatabase()will be executed once this line is reached.

The second type is lazy variables, the will not be evaluated until the variable is used, and the syntax like:

lazy val x: Int = getXValueFromDatabase()

The third type is defined like functions (actually there are functions) and defined using the function definition syntax like:

def x: Int = getXValueFromDatabase()

and will be evaluated each time the symbol x is referred.
see this SO question: http://stackoverflow.com/q/9449474

2)
In the java world, there's variables like the first type in scala and methods like the third type in scala, and also there's Initialization-on-demand holder idiom

The most common used is the variables and methods.

So, how can we use it in Logging?

Look to the javadoc from sfl4j
void info(String format,
        Object... arguments)
Log a message at the INFO level according to the specified format and arguments.
This form avoids superfluous string concatenation when the logger is disabled for the INFO level. 
What it can do for you is that it defers the string concatenation until the framework do a check like the following:

 if (!isLoggable(level)) {
     return;
 }

but this is not enough, calling external service/resource to get the information to log is resource wasting when the log level is higher than the one specified in the application.

So, can we make use of lazy or even function calls here, where the logging peace of data is not calculated until the check of (isLoggable) is done?

Yes, JUL did it, using Java8 Supplier interface

Look to this example:

package test;

import java.util.logging.FileHandler;
import java.util.logging.Level;
import java.util.logging.Logger;

public class LoggingExample {

    public static void main(String[] args) throws Exception {
        Logger logger = Logger.getGlobal();
        logger.addHandler(new FileHandler(System.getenv("HOME") + "/logging_example.log"));

        logger.setLevel(Level.INFO);

        logger.fine(() -> String.format("V1 - the value of the expensive resource is \"%s\"",
                getSomeExpensiveResourceListExternalServiceCall("V1")));

        logger.fine(String.format("V2 - the value of the expensive resource is \"%s\"",
                getSomeExpensiveResourceListExternalServiceCall("V2")));

        logger.info(() -> String.format("V3 - the value of the expensive resource is \"%s\"",
                getSomeExpensiveResourceListExternalServiceCall("V3")));

        logger.info(String.format("V4 - the value of the expensive resource is \"%s\"",
                getSomeExpensiveResourceListExternalServiceCall("V4")));
    }

    private static Object getSomeExpensiveResourceListExternalServiceCall(String version) {
        System.out.println(version + " - GETTING THE EXPENSIVE RESOURCE");
        return "some expensive resource";
    }
}

I run this example with setting the logger level to info (as shown) and here's the std out:

V2 - GETTING THE EXPENSIVE RESOURCE
V3 - GETTING THE EXPENSIVE RESOURCE
V4 - GETTING THE EXPENSIVE RESOURCE

Not that, V1 does not call the getSomeExpensiveResourceListExternalServiceCall at all.
This is because the supplier will never be executed until the following check is done:

 if (!isLoggable(level)) {
     return;
 }

This is a good usage of Java 8, and every single logging framework should make use of it.

No comments: