Why calling LoggerFactory.getLogger(...) every time is not recommended?

user_468172 0
Viewed 78664

I've read tons of posts and documents (on this site and elsewhere) pointing that the recommended pattern for SFL4J logging is:

public class MyClass {
    final static Logger logger = LoggerFactory.getLogger(MyClass.class);

    public void myMethod() {
        //do some stuff
        logger.debug("blah blah blah");
    }
}

My boss prefers we just use a wrapper to intercept log calls and avoid boiler plate code for declaring the logger on every class:

public class MyLoggerWrapper {
    public static void debug(Class clazz, String msg){
        LoggerFactory.getLogger(clazz).debug(msg));
    }
}

and simply using it like this:

public class MyClass {

    public void myMethod() {
        //do some stuff
        MyLoggerWrapper.debug(this.getClass(), "blah blah blah");
    }
}

I presume instantiating a logger every time we log is somewhat expensive but I've been unable to find any document backing that assumption. Besides he says surely the framework (LogBack or Log4J we're still deciding) will "cache" the loggers and also that in any case the servers are running very much below their capacity so it is not an issue.

Any help pointing out potential problems with this approach?

slf4j logback log4j logging java
11 Answers

There are two reasons why your boss' approach does not achieve what he thinks.

The smaller reason is that the overhead of adding a static logger is negligible. After all, the logger setup is part of this pretty lengthy sequence:

  • Locate the class, i.e. walk all the .jars and directories. Java code. Pretty big overhead due to filesystem calls. May create helper objects, e.g. with File.
  • Load the bytecode, i.e. copy it into a data structure inside the JVM. Native code.
  • Validate the bytecode. Native code.
  • Link the bytecode, i.e. iterate through all the class names in the bytecode and replace them with pointers to the referred-to class. Native code.
  • Run static initializers. Triggered from native code, the initializers are Java code of course. The Logger gets created here.
  • After a while, maybe JIT-compile the class. Native code. Huge overhead (compared to the other operations anyway).

Also, your boss saves nothing.
The first call to LoggerFactor.getLogger will create the logger and place it in a global name-to-Logger HashMap. This will happen even for the isXxxEnabled calls, because to do these you need to construct the Logger object first...
The Class object will carry an extra pointer for the static variable. This is offset by the overhead of passing the clazz parameter - an additional instruction and an additional pointer-sized reference in the bytecode, so you lose at least one byte in class size already.

The code is also going through an extra indirection, LoggerFactory.getLogger(Class) uses Class#getName and delegates to LoggerFactory.getLogger(String).

Now if your boss is not after performance but after the ability to simply copy over the static declaration, he can use a function that inspects the call stack and retrieves the class name. The function should be annotated @CallerSensitive, and it's still something that needs to be tested whenever a new JVM is used - not nice if you do not control the JVM that the user is running the code on.

The least problematic approach would be to have an IDE that checks the logger instantiation. This probably means finding or writing a plugin.

user_69440680
Related