What is the proper way to use a Logger in a Serializable Java class?

Question

I have the following (doctored) class in a system I'm working on and Findbugs is generating a SE_BAD_FIELD warning and I'm trying to understand why it would say that before I fix it in the way that I thought I would. The reason I'm confused is because the description would seem to indicate that I had used no other non-serializable instance fields in the class but bar.model.Foo is also not serializable and used in the exact same way (as far as I can tell) but Findbugs generates no warning for it.

import bar.model.Foo;

import java.io.File;
import java.io.Serializable;
import java.util.List;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Demo implements Serializable {

    private final Logger logger = LoggerFactory.getLogger(this.getClass());
    private final File file;
    private final List<Foo> originalFoos;
    private Integer count;
    private int primitive = 0;

    public Demo() {
        for (Foo foo : originalFoos) {
            this.logger.debug(...);
        }
    }

    ...

}

My initial blush at a solution is to get a logger reference from the factory right as I use it:

public DispositionFile() {
    Logger logger = LoggerFactory.getLogger(this.getClass());
    for (Foo foo : originalFoos) {
        this.logger.debug(...);
    }
}

That doesn't seem particularly efficient, though.

Thoughts?

Answer 1

Firstly, don't optimize prematurely. It may be that LoggerFactory.getLogger() is fast enough, and contributes no significant overhead to execution time. If in doubt, profile it.

Secondly, the reason that findbugs isn't complaining about the use of Foo is because the class doesn't have a field of type Foo, it has a field of type List. The generics are erased at compile time, there is no actual reference to Foo in the class, as far as the field definition is concerned. At runtime, the fact that Foo is non-serializable would cause an exception if you tried to serialize an instance of the Demo class, but findbugs can't know this.

My first reaction would be to make the Logger a static field, rather than an instance field. Should work fine in this situation.

public class Demo implements Serializable {
   private static final Logger logger = LoggerFactory.getLogger(Demo.class);

   // .. other stuff
}

Answer 2

I don't want things to take off on a tangent, but have you considered the conventional initialization of loggers?

private static final Logger logger = LoggerFactory.getLogger(Demo.class);

If you don't really need different loggers for each instance (which is unusual), the problem would go away.

By the way, the author of SL4J said (in a critique of Log4J wrappers like commons-logging),

More often than not, these wrappers are of doubtful quality such that the cost of inactive (or disabled) logging statements is multiplied by a factor of 1'000 (one thousand) compared to direct log4j usage. The most common error in wrapper classes is the invocation of the Logger.getLogger method on each log request. This is guaranteed to wreak havoc on your application's performance. Really!!!

That would suggest that your alternative idea of getting the logger each time you need it is not recommended.

Answer 3

FindBugs is misleading you in this particular case because the org.slf4j.Logger interface is not marked as java.io.Serializable. However, SLF4J logger implementations that ship with SLF4J all support serialization out-of-the-box. Try it. You'll see that it works.

Here is an excerpt from the SLF4j FAQ:

Contrary to static variables, instance variables are serialized by default. As of SLF4J version 1.5.3, logger instances survive serialization. Thus, serialization of the host class no longer requires any special action, even when loggers are declared as instance variables. In previous versions, logger instances needed to be declared as transient in the host class.

See also http://slf4j.org/faq.html#declared_static

Answer 4

My initial reaction is to wonder if it even makes sense to serialize a Logger instance in your object. When you deserialize it later, is it really all that fair to expect the Logger's environment to be correct? I think I would rather just go with this and call it a day:

private transient Logger logger = LoggerFactory.getLogger(this.getClass());