SLF4j Tutorial | Log4J Tutorial | LogbackTutorial

Introduction

Simple Logging Facade for Java (abbreviated SLF4J) – acts as a facade for different logging frameworks (e.g. java.util.logging, logback, Log4j). It offers a generic API making the logging independent of the actual implementation.

This allows for different logging frameworks to coexist. It also helps migrate from one framework to another. Finally, apart from standardized API, it also offers some “syntactic sugar”.

This article will discuss the dependencies and configuration needed to integrate SLF4J with Log4j2, Logback, Log4J2 and Jakarta Commons Logging.

2. The Log4j2 Setup

To use SLF4J with Log4j2 you should add the following libraries to pom.xml:

<dependency>

    <groupId>org.apache.logging.log4j</groupId>

    <artifactId>log4j-api</artifactId>

    <version>2.7</version>

</dependency>

<dependency>

    <groupId>org.apache.logging.log4j</groupId>

    <artifactId>log4j-core</artifactId>

    <version>2.7</version>

</dependency>

<dependency>

    <groupId>org.apache.logging.log4j</groupId>

    <artifactId>log4j-slf4j-impl</artifactId>

    <version>2.7</version>

</dependency>

The latest version can be found here: log4j-api, log4j-core, log4j-slf4j-impl.

The actual logging configuration is adhering to native Log4j 2 configuration. Let’s see how the Logger instance is created:

public class SLF4JExample {

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

    public static void main(String[] args) {

        logger.debug("Debug log message");

        logger.info("Info log message");

        logger.error("Error log message");

    }

}

Note that the Logger and LoggerFactory belong to the org.slf4j package. An example of a project, running with the explained configuration is available here.

3. The Logback Setup

To use SLF4J with Logback you don’t need to add SLF4J to your classpath. Logback is already using SLF4J. It’s considered as the reference implementation. We need only to include the Logback library:

<dependency>

    <groupId>ch.qos.logback</groupId>

    <artifactId>logback-classic</artifactId>

    <version>1.1.7</version>

</dependency>

The latest version can be found here: logback-classic.

The configuration is Logback-specific but works seamlessly with SLF4J. With the proper dependencies and configuration in place, the same code from previous sections can be used to handle the logging.

4. The Log4j Setup

In the previous sections, we covered a use-case where SLF4J “sits” on top of the particular logging implementation. Used like this, it completely abstracts away the underlying framework.

There are cases when an existing logging solution cannot be replaced e.g. due to third-party requirements. This, however, does not mean that the project is “sentenced” only to the already used framework.

SLF4J can be configured as a bridge, where the calls to an existing framework are redirected to it. Let’s add the necessary dependencies to create a bridge for Log4j:

<dependency>

    <groupId>org.slf4j</groupId>

    <artifactId>log4j-over-slf4j</artifactId>

    <version>1.7.21</version>

</dependency>

With the dependency in place (check for latest at log4j-over-slf4j), all the calls to Log4j will be redirected to SLF4J. Consider the official documentation to learn more about bridging existing frameworks.

Just as with the other frameworks Log4j can serve as an underlying implementation. Let’s add the necessary dependencies:

<dependency>

    <groupId>org.slf4j</groupId>

    <artifactId>slf4j-log4j12</artifactId>

    <version>1.7.21</version>

</dependency>

<dependency>

    <groupId>log4j</groupId>

    <artifactId>log4j</artifactId>

    <version>1.2.17</version>

</dependency>

Latest version could be found here for slf4j-log4j12 and log4j. An exemplary project, configured in the manner explained is available here.

5. JCL Bridge Setup

In the previous sections, we showed how the same code base can be used to support logging using different implementations. While this is the main promise and strength of SLF4J, it is also the goal behind JCL (Jakarta Commons Logging or Apache Commons Logging).

JCL is, by its intentions, a framework similar to SLF4J. The major difference is that JCL resolves the underlying implementation during execution-time through a class loading system. This approach is perceived problematic in cases where there are custom classloaders at play.

SLF4J resolves its bindings at compile-time. It’s perceived simpler yet powerful enough.

Luckily, two frameworks can work together in the bridge mode:

<dependency>

    <groupId>org.slf4j</groupId>

    <artifactId>jcl-over-slf4j</artifactId>

    <version>1.7.21</version>

</dependency>

The latest dependency version can be found here jcl-over-slf4j.

As with the other cases, the same code-base will run just fine. An example of a complete project running this setup is available here.

6. Further SLF4J Goodness

SLF4J provides additional that can make logging more efficient and code more readable. For example, SLF4J provides a very useful interface for working with parameters:

String variable = "Hello John";

logger.debug("Printing variable value: {}", variable);

Here is the code example of Log4j that doing the same thing:

String variable = "Hello John";

logger.debug("Printing variable value: " + variable);

As you can see, Log4j will concatenate Strings regardless of debug level being enabled or not. In high-load applications, this may cause performance issues. SLF4J will concatenate Strings only when the debug level is enabled. To do the same with Log4J you need to add extra if block which will check if debug level is enabled or not:

String variable = "Hello John";

if (logger.isDebugEnabled()) {

    logger.debug("Printing variable value: " + variable);

}

SLF4J standardized the logging levels which are different for the particular implementations. The FATAL logging level got dropped (it was introduced in Log4j) based on the premise that in a logging framework, we should not decide when an application should be terminated.

The logging levels used are ERROR, WARN, INFO, DEBUG, TRACE.

Note: in all examples we will assume the following imports:

import org.slf4j.Logger;

import org.slf4j.LoggerFactory;

1. Logger definition

Wrong way:

W1a. Logger log = LoggerFactory.getLogger(MyClass.class);

W1b. private Logger logger = LoggerFactory.getLogger(MyClass.class);

W1c. static Logger LOGGER = LoggerFactory.getLogger(AnotherClass.class);

Correct way:

C1a. private static final Logger LOGGER = LoggerFactory.getLogger(MyClass.class);

C1b. private final Logger logger = LoggerFactory.getLogger(getClass());

General rule: the logger should be final and private because there are no reasons to share it with other classes or to re-assign it.

On the contrary there is no general agreement if the logger should be static or not. SLF4J plugin favors non static version (C1b) while PMD (“LoggerIsNotStaticFinal” rule) and Sonar (squid rule S1312) prefer a static logger (C1a) so both options should be considered as valid.

Additional info:

[SLF4J FAQ](http://slf4j.org/faq.html#declared_static)
[Apache Commons Static Log](http://wiki.apache.org/commons/Logging/StaticLog).

Please note that

in the static version (C1a), the logger name is usually in uppercase characters as all constant fields. If not, PMD will report a “VariableNamingConventions” violation.
in both cases, the suggested name is “logger/LOGGER” and not “log/LOG” because some naming conventions avoid too short names (less than four characters). Moreover log is the verb, more suited for a method name.
the W1c is wrong because we are referring to a class (AnotherClass) which is not the class where the logger is defined. In the 99% of the cases, this is due to a copy & paste from one class to another.

Related FindBugs (SLF4J plugin) checks:

SLF4J_LOGGER_SHOULD_BE_PRIVATE
SLF4J_LOGGER_SHOULD_BE_NON_STATIC
SLF4J_LOGGER_SHOULD_BE_FINAL
SLF4J_ILLEGAL_PASSED_CLASS

2. Format string

Wrong way:

W2a. LOGGER.info("Obj=" + myObj);

W2b. LOGGER.info(String.format(“Obj=%s”, myObj));

Correct way:

C2. LOGGER.info("Obj={}",myObj);

General rule: the format string (the first argument) should be constant, without any string concatenation. Dynamic contents (the myObj value in the example) should be added using the placeholders (the ‘{}’ ).

Motivation is simple: we should delay logging message creation after the logger has established if the message should be logged or not, depending on the current logging level. If we use string concatenation, message is built any way, regardless the logging level which is a waste of CPU and memory resources.

Related FindBugs (SLF4J plugin) checks:

SLF4J_FORMAT_SHOULD_BE_CONST Format should be constant
SLF4J_SIGN_ONLY_FORMAT Format string should not contain placeholders only

Related FindBugs (FB Contrib plugin) checks:

LO_APPENDED_STRING_IN_FORMAT_STRING Method passes a concatenated string to SLF4J’s format string

3. Placeholder arguments

Wrong way:

W3a. LOGGER.info("Obj={}",myObj.getSomeBigField());

W3b. LOGGER.info("Obj={}",myObj.toString());

W3c. LOGGER.info("Obj={}",myObj, anotherObj);

W3d. LOGGER.info("Obj={} another={}",myObj);

Correct way:

C3a. LOGGER.info("Obj={}",myObj);

C3b. LOGGER.info("Obj={}",myObj.log());

General rule: the placeholder should be an object (C3a), not a method return value (W3a) in order to post-pone its evaluation after logging level analysis (see previous paragraph). In W3a example, the mehod getSomeBigField() will be always called, regardless the logging level. For the same reason, we should avoid W3b which is semantically equivalent to C3a but it always incurs in the toString() method invocation.

Solutions W3c and W3d are wrong because the number of placeholders in the format string does not match the number of placeholders arguments.

Solution C3b could be somehow misleading because it includes a method invocation but it could be useful whenever the myObj contains several fields (for example it is a big JPA entity) but we do not want to log all its contents.

For example, let’s consider the following class:

public class Person {

private String id;

private String name;

private String fullName;

private Date birthDate;

private Object address;

private Map attributes;

private List phoneNumbers;

its toString() method will most probably include all fields. Using the solution C3a, all their values will be printed in the log file.

If you do not need all this data, it is useful to define a helper method like the following:

public String log() {

return String.format("Person: id=%s name=%s", this.id, this.name);

}

which prints relevant information only. This solution is also CPU and memory lighter than toString().

What is relevant ? It depends on the application and on the object type. For a JPA entity, I usually include in the log() method the ID field (in order to let me find the record in the DB if I need all columns data) and, may be, one or two important fields.

For no reason, passwords fields and/or sensitive info (phone numbers,…) should be logged. This is an additional reason to not log using toString().

Related FindBugs (SLF4J plugin) checks:

SLF4J_PLACE_HOLDER_MISMATCH

4. Debug messages

IMPORTANT: rule #4 (see 5 rules article) guide us to use a guarded debug logging

if (LOGGER.isDebugEnabled()) {

LOGGER.debug(“Obj={}”, myObj);

}

Using SLF4J, if the placeholder argument is an object reference (see solutions C3a/C3b), we can use avoid the if in order to keep the code cleaner.

So it is safe to use the following:

LOGGER.debug(“Obj={}”, myObj);

5. Exceptions

Proper exceptions logging is an important support for problems analysis but it is easy to neglect its usefulness.

Wrong way:

W5a. catch (SomeException ex) { LOGGER.error(ex);}..

W5b. catch (SomeException ex) { LOGGER.error("Error:" + ex.getMessage());}..

Correct way:

C5. catch (SomeException ex) { LOGGER.error("Read operation failed: id={}", idRecord, ex);}..`

General rules:

Do not remove the stack trace information by using getMessage() (see W5b) and not the complete exception. The stack trace often includes the real cause of the problem which is easily another exception raised by the underlying code. Logging only the message will prevent us to discover the real cause of the problem.
Do show significant (for the human which will analyze the log file) information in the logging message showing a text explaining what we wanted to perform while the exception was raised (not the exception kind or messages like “error”: we know already something bad happened). What we need to know is what we were doing and on which data.

The C5 example tells we were trying to read the record with a specific ID whose value has been written in the log with the message.

Please note that C5 use one placeholder in the format string but there are two additional arguments. This is not an error but a special pattern which is recognized by SLF4J as an exception logging case: the last argument (ex in the C5 example) is considered by SLF4J as a Throwable (exception) so it should be not included in the format string.

Coding Interview Q&A

Search This Blog