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?

Solution 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
}

Solution 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.

Solution 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

Solution 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());

View more solutions

Comments

[meriton]

Nitpick: Findbugs could know this: a field's declared type (including any type parameters / wildcards) is written to the classfile and hence available for static analysis.

[meriton]

Ah, no it can't: Findbugs doesn't know that a List will actually hold a non-transient reference of type T. (A list returned by Collections.emptyList() doesn't, for instance).

[matt b]

To be fair, the next sentence of that article says "Of course, not all wrappers are of poor quality. For example, the commons-logging API is a prime example of a reasonable implementation. "

[matt b]

Also arguably loggers should always be static unless you need a dynamic logger name or to share instances with subclasses or anything similar, so +1 for that.

[Tim Visher]

My obfuscation was too effective! :) In the real class there are many references to that List. I was trying to compress for space. How would that change your answer? Thanks for the response so far!

[Tim Visher]

Also, including a code snippet for the static field suggestion would make this answer acceptable. :)

[skaffman]

@Tim: As requested :) Also, references to the List are fine. Direct (i.e. non-generic) references to Foo should trigger the same warning.

[Vishy]

When benchmarking the logger, you can find that it spends far more time writing the log entry to disk, or the console than looking up the logger. IMHO it is usually made a private static final (which would be in UPPER_CASE) to make logging lines shorter the write. Does anyone know why people make constants in UPPER_CASE but not for loggers?

[Ceki]

FindBugs is misleading you in this particular case. SLF4J loggers support serialization out-of-the-box.

[skaffman]

Maybe he's using a version older than 1.5.3, in that case

[Ceki]

FindBugs probably gets confused because the org.slf4j.Logger interface is not marked as Serializable even in SLF4J versions 1.5.3 and later.

[user207421]

... as long as you take steps to have it recreated on deserialization.