Search code examples
javaloggingslf4j

How to factor out conditional log checks in Java 8 & SLF4J?


I am trying to factor out if (log.isInfoEnabled()) or if (log.isWarnEnabled()) statements so I am thinking to create an interface in Java 8 like below however I am not sure if I could run into any problems?

public interface Logging {

    Logger log_ = LoggerFactory.getLogger(Thread.currentThread().getContextClassLoader().getClass());

    default void logInfo(String... messages) {
        if (log_.isInfoEnabled()) {
            String meg = String.join("log message: ", messages)
            log_.info(msg);
        }
    }
}


public class Hello implements Logging {

    //Imagine this function is called lot of times like imagine
    // an infinite loop calling this function
    public void doSomething(String name) {
        if (name.equals("hello")) {
            logInfo("What class name does the log print here ? ")  
        }
    }

     //Imagine this function is called lot of times like imagine
    // an infinite loop calling this function
   public void doSomething2(String name) {
        if (name.equals("hello2")) {
            logInfo("What class name does the log print here ? ")  
        }
    }

    //Imagine this function is called lot of times like imagine
    // an infinite loop calling this function
    public void doSomething3(String name) {
        if (name.equals("hello3")) {
            logInfo("What class name does the log print here ? ")  
        }
    }
}

vs

public class Hello {

    Logger log_ = LoggerFactory.getLogger(Hello.class);

    public void doSomething(String name) {
        if (name.equals("hello")) {
            if (log_.isInfoEnabled()) { // Don't want to have this code everywhere
                logInfo("What class name does the log print here ? ") 
            }
        }
    }
}

Are these two equivalent? Any problems if I go with the Logging interface above?


Solution

  • I am trying to factor out if (log.isInfoEnabled()) or if (log.isWarnEnabled()) statements

    I think you didn't understand how and why the if (log.isLevelXXXEnabled()){...} pattern is used.

    What you are writing here :

    public void doSomething(String name) {
        if (name.equals("hello")) {
            if (log_.isInfoEnabled()) { // Don't want to have this code everywhere
                logInfo("What class name does the log print here ? ") 
            }
        }
    }
    

    has really no need to be enclosed by :

    if (log_.isInfoEnabled()){
    

    Why ?
    Because you pass a String to log that doesn't require any computation : "What class name does the log print here ?" to your logger.
    Besides, loggers are already designed to write the log only if the actual level of the logger matches with the requested log level.

    Now, suppose you passed an object with a expensive toString() method.
    The logger invokes indeed the toString() method of the passed object to log when it performs actually the log.
    But in this case, using a check before logging is still useless.

    Suppose myObject is a variable referring to an instance of class with a toString() performing multiple computations or simply a collection of objects. This is helpless :

    if (log_.isInfoEnabled()) { 
        logInfo(myObject); 
    }
    

    as the logger implementation will perform myObject.toString() only if the effective log level of the logger matches with the requested level for logging.

    Using this check log pattern makes sense only when you have to perform a relatively expensive computation for the passed object.
    Generally, it is when you perform yourself a computation and you provide it as parameter to the log operation.
    For example :

    if (log_.isInfoEnabled()) { 
        log_.info("name :" + myPerson.getName() + ", order history :" + myPerson.getOrders()); 
    }
    

    Here it makes sense not because you spare 4 concatenations but because myPerson.getOrders() is a collection with potential hundreds elements and invoking toString() on it should be done only if you really log.

    Now how do you think design a generic method that could do this specific check and any other specific check for you ?
    It is not possible.
    In fact, what you try to do is possible but will only repeat what the logger libraries already do for you.
    The specific case where you should do the check because it is expensive has to be performed by you for each specific case.

    Now according to preferences, you can of course replace this :

    if (log_.isInfoEnabled()) { 
        log_.info("name :" + myPerson.getName() + ", order history :" + myPerson.getOrders()); 
    }
    

    by this other syntax :

    log_.info("name : {}, order history : {}", myPerson.getName(), myPerson.getOrders()); 
    

    that relies on the

    public void info(String format, Object... arguments);
    

    method of the org.slf4j.Logger class.

    Using if (log_.isInfoEnabled()) { or public void info(String format, Object... arguments); doesn't change really the problem as you should always think when using the way to spare potential computation.