Home > English, java, work > Setting up your logging with SLF4J – How to automate the prevention of mistakes and disappearing log statements

Setting up your logging with SLF4J – How to automate the prevention of mistakes and disappearing log statements

Properly setting up your logging is not as trivial as many people think. The big problem is that many people will stop worrying about their logging setup once they see logging output. There is a chance you forgot about the output of a few other logging libraries you transitively got into your project. This article will show you which libraries to use or exclude to prevent missing log statements. Then I’ll show a method to fail your build when a conflicting library accidentally crept into your project.

There are many logging libraries available. The five main players (log4j 1, log4j 2, logback, java.util.logging/JUL, commons-logging) will probably end up in all sizeable. Since you don’t want to maintain multiple configuration files or collect logging from several different places you can use a logging facade with an implementation. A common combination is SLF4J with Logback, so I will use this pair for clarity. This article however is also applicable for SLF4J with log4j and java.util.logging (JUL for short). You just have to use other libraries. I also use Maven, but this should be applicable to other build tools too.

Use SLF4J for logging

In your own libraries you shouldn’t depend on any logging implementation (like Logback or log4j). Use the SLF4J-api and let the users of your library decide which implementation they want to use. The SLF4j-api is also the foundation of your logging setup. In your pom.xml add the following dependency :

<properties>
	<slf4j.version>1.7.22</slf4j.version>
</properties>
<dependencies>
	<dependency>
		<groupId>org.slf4j</groupId>
		<artifactId>slf4j-api</artifactId>
		<version>${slf4j.version}</version>
	</dependency>
</dependencies>

I use a placeholder for the version because it’ll make it easier to add other SLF4J libraries later and make sure all versions are the same.

A log definition in a Java class should look like (also for log4j and JUL):

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

private static final Logger log = 
    LoggerFactory.getLogger(HarrieYadayadaProcessor.class);

Note that I prefer ‘log’ since it’s the least polluting (but LOG, LOGGER or logger are also ok, just be consistent).

The main thing here is that you don’t use log implementations in your code, just the SLF4J-api.

Building bridges

The second step is to route all logging (libraries that use another implementation than you do) to SLF4J, this is done via bridges. Follow the arrows on the diagram [https://www.slf4j.org/legacy.html] (click on the diagram to make it readable) to see which bridges you need. Because Logback is our logging implementation we use the top left diagram (when you use another implementation you have to use the libraries in the other diagrams).
I strongly advise to use all bridges (belonging to the used implementation), since you never know which libraries will end up in your project eventually (or what strange things other developers do after you left a project).

Add the following dependencies to the dependencies-section of your pom.xml :

<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>jcl-over-slf4j</artifactId>
    <version>${slf4j.version}</version>
</dependency>
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>log4j-over-slf4j</artifactId>
    <version>${slf4j.version}</version>
</dependency>
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>jul-to-slf4j</artifactId>
    <version>${slf4j.version}</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-to-slf4j</artifactId>
    <version>2.8</version>
</dependency>

The SLFJ4 bridges are some kind of workarounds, they use the same package and class names as the actual logging implementation they’re bridging. It isn’t pretty, but unfortunately the only solution. This workaround however causes conflicts, because Java doesn’t have a clue which class is the right one to use. There’s also a big chance Java doesn’t care about this and your log statements will end up nowhere.

Log4j 1 vs Log4j 2

Log4j 2 seems just a higher version number, but it’s actually a completely different library.
When you get errors with dependencies on Log4j it’s best to check the package name where the error occurs in. When it starts with org.apache.log4j we’re dealing with Log4j 1. Log4j 2 uses the package org.apache.logging.log.

When you’re not using Log4j 2 as your logging implementation add (don’t replace) the following bridge [https://logging.apache.org/log4j/2.0/log4j-to-slf4j/index.html]:

<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-to-slf4j</artifactId>
    <version>2.8</version>
</dependency>

Note that it is important to add a bridge for both versions of Log4j!

When Log4j 2 is your logging implementation add : [https://logging.apache.org/log4j/2.0/log4j-slf4j-impl/index.html]

<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-slf4j-impl</artifactId>
    <version>2.8</version>
</dependency>

Note that you still have to add a bridge for Log4j 1!

Excluding all ‘wrong’ libraries

Now that our bridging is set up correctly we have to remove the libraries that cause conflicts (usually missing log statements). I will call those libraries wrong and bad, that doesn’t mean the library is of dubious quality, just that it can cause conflicts in your project.

Maven has a nice command to show a tree of all your dependencies, with the includes parameter you can even narrow it down to groupId’s, artifactId’s and use wildcards.

# shouldn't show results
mvn dependency:tree -Dincludes=commons-logging*
mvn dependency:tree -Dincludes=log4j*
mvn dependency:tree -Dincludes=org.apache.logging.log4j:log4j
mvn dependency:tree -Dincludes=org.apache.logging.log4j:log4j-slf4j-impl
mvn dependency:tree -Dincludes=org.slf4j:slf4j-log4j12
mvn dependency:tree -Dincludes=org.slf4j:slf4j-jdk14

# should show results since our implementation is logback
mvn dependency:tree -Dincludes=ch.qos.logback*

# search in ALL projects
find . -maxdepth 1 -type d \( ! -name . \) -exec bash -c \
  "cd '{}' && pwd && mvn dependency:tree -Dincludes=log4j* | grep 'compile\|runtime'" \;

The first six statements shouldn’t show any result, when the do you have to exclude some things.
When you have a large code repository the last statement is very useful, it searches all projects in the directory where this statement is executed. It will display the use of log4j compile and runtime dependencies.

Pro-tip: don’t blindly copy/paste statements from blog.

When you have found a bad library you have to add an exclusions-section to the dependency. In this case the bad apple is a dependency on log4j and slf4j-log4j12 in zookeeper :

<dependency>
    <groupId>org.apache.zookeeper</groupId>
    <artifactId>zookeeper</artifactId>
    <version>${zookeeper.version}</version>
    <exclusions>
        <exclusion>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-log4j12</artifactId>
        </exclusion>
        <exclusion>
            <artifactId>log4j</artifactId>
            <groupId>log4j</groupId>
        </exclusion>
    </exclusions>
</dependency>

Enforcer plugin to the rescue : breaking the build

It’s of course tedious and error prone to do this many times. A solution for this problem is to automate this check with the Maven enforcer plugin. This plugin can break the build when a (transitive) dependency is (unintentionally) included that might mess up your logging.

Besides the unused logging libraries it’s also a good idea to prevent the bridges for the other logging frameworks from appearing in your project. Better safe than sorry :

<plugin>
    <groupId>org.apache.maven.plugins</groupId>
    <artifactId>maven-enforcer-plugin</artifactId>
    <version>1.4.1</version>
    <executions>
        <execution>
            <id>enforce-banned-dependencies</id>
            <goals>
                <goal>enforce</goal>
            </goals>
            <configuration>
                <rules>
                    <bannedDependencies>
                      <excludes>
                        <exclude>log4j:log4j</exclude>
                        <exclude>commons-logging:commons-logging</exclude>
                        <exclude>org.slf4j:slf4j-log4j12</exclude>
                        <exclude>org.apache.logging.log4j:log4j</exclude>
                        <exclude>org.apache.logging.log4j:log4j-slf4j-impl</exclude>
                        <exclude>org.slf4j:slf4j-jdk14</exclude>
<!-- prevents ERROR in ch.qos.logback.core.joran.action.NestedBasicPropertyIA 
                      - Unexpected aggregationType AS_BASIC_PROPERTY_COLLECTION -->
                        <exclude>ch.qos.logback:logback-classic:[1.1.7]</exclude> 
                      </excludes>
                    </bannedDependencies>
                </rules>
                <fail>true</fail>
            </configuration>
        </execution>
    </executions>
</plugin>

I also included the exclusion of a specific version of logback since it was causing error. It’s also possible to to exclude a range of versions. If you want to exclude versions older than 1.1.9 you use (,1.1.9). More information on the brace notation.

Final thoughts

While writing this article I found a small mistake in our project, our checks weren’t strict enough. Logging might seem simple, but there are quite a few things that can go wrong. When you fixed everything don’t think you’re done. Software development is an ongoing process so things can break again after the next push. The best solution is to automate prevention.

Background information

Configuring Maven to use SLF4J
Logging Dependencies in Spring

Advertisements
Categories: English, java, work Tags: , , , , ,

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: