Notes on slf4j

Russell Bateman
2009
last update:

For my notes on log4j, see log4j.html. That project was successfully completed. However, I found that log4j suffers from severe performance penalties when things like classname, method name, line number, etc. are to be included in the log. That is why I've started to investigate slf4j.


Using slf4j

slf4j logging is pretty easy and promises to be a lot more performant than log4j. Here's a discussion: http://xhab.blogspot.com/2007/03/new-logging-experience.html. It's a very thorough treatment (overview and discussion).

I'm presently investigating. The documentation seems very clean, however, it is severely tainted by log4j baggage: the author assumes that you're coming to slf4j from log4j or another system and not that you're ready to start fresh. In fact, at this point, I don't even know if you can isolate your usage to just slf4j, but my preliminary attempts to write sample code for it appear to support that you can. I can't seem to get debug messages to come out, only info for now. See sample code and console output below.

Other crucial links to slf4j:

Source code sample

Here is the sample code for the output we'll be studying.

	package com.etretatlogiciels.samples.slf4j;

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


	public class SLF4J
	{
	  Integer             cur, old;
	  final static Logger logger = LoggerFactory.getLogger( SLF4J.class );

	  public void setTemperature( Integer temperature )
	  {
	    old = cur;
	    cur = temperature;
	    logger.debug( "Temperature set to {}. Old temperature was {}.", cur, old );
	    if( temperature.intValue() > 50 )
	      logger.info( "Temperature has risen above 50 degrees." );
	  }

	  public static void main( String[] args )
	  {
	    SLF4J  slf4j = new SLF4J();
	    slf4j.setTemperature( 60 );
	  }
	}

Console output

	29 [main] INFO com.etretatlogiciels.samples.slf4j.SLF4J - Temperature has risen above 50 degrees.

Getting warnings and NoSuchMethodError with slf4j and logback

Here's my experience. It was nasty and caused hair-pulling for months with ugly work-arounds, but I think I've solved it and I posted this response on stackoverflow.com:

I mix a lot of software from diverse sources together in my product. I encountered this problem first with NiFi JARs, then more recently with Cassandra JARs all over again. I had already insisted in pom.xml that I have the same version of slf4j everywhere:

<slf4j.version>[1.7.25]</slf4j.version>
...
<dependency>
  <groupId>org.slf4j</groupId>
  <artifactId>slf4j-api</artifactId>
  <version>${slf4j.version}</version>
</dependency>
<dependency>
  <groupId>org.slf4j</groupId>
  <artifactId>slf4j-simple</artifactId>
  <version>${slf4j.version}</version>
</dependency>
... (all the slf4j JARs I needed)

Then, I told Maven I wanted Cassandra without whatever it was bringing in for slf4j:

<dependency>
  <groupId>org.apache.cassandra</groupId>
  <artifactId>cassandra-all</artifactId>
  <version>${cassandra.version}</version>
  <exclusions>
    <exclusion>
      <groupId>org.slf4j</groupId>
      <artifactId>slf4j-log4j12</artifactId>
    </exclusion>
    <exclusion>
      <groupId>org.slf4j</groupId>
      <artifactId>slf4j-simple</artifactId>
    </exclusion>
</dependency>

However, like you, I was getting complaints from

Exception in thread "main" java.lang.NoSuchMethodError: \
  org.slf4j.helpers.MessageFormatter.arrayFormat(Ljava/lang/String;\
  [Ljava/lang/Object;)Lorg/slf4j/helpers/FormattingTuple;
  at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:112)

From mvn dependency:tree, I found out that I was getting logback 1.1.3 which wasn't matching what Cassandra was apparently using (0.9-something like you). So, I excluded getting logback too by adding these exclusions to slf4j ones already there:

<dependency>
  <groupId>org.apache.cassandra</groupId>
  <artifactId>cassandra-all</artifactId>
  <version>${cassandra.version}</version>
  <exclusions>
    <exclusion>
      <groupId>org.slf4j</groupId>
      <artifactId>slf4j-log4j12</artifactId>
    </exclusion>
    <exclusion>
      <groupId>org.slf4j</groupId>
      <artifactId>slf4j-simple</artifactId>
    </exclusion>
    <exclusion>
      <groupId>ch.qos.logback</groupId>
      <artifactId>logback-core</artifactId>
    </exclusion>
    <exclusion>
      <groupId>ch.qos.logback</groupId>
      <artifactId>logback-classic</artifactId>
    </exclusion>
</dependency>

...whereupon, the problem I had and you are reporting here, went away.


Logging fails to behave or to work at all...

...due to multiple, self-defeating bindings!

Symptoms include apparent failure to observe configuration in logback.xml, log4j.xml, etc., when you set a log level other than INFO, etc. What's probaby happening is that your configuration isn't consulted at all because logging is broken—yielding defaults only.

If SLF4J warning or error messages and their meanings: Multiple bindings were found on the classpath or "logging stuff just doesn't quite work," as noted, then multiple bindings may be available on the class path. The solution is to select one and only one binding you wish to use, and remove the other bindings. For example, if you have both

on the class path and you wish to use the full API or no-op binding, then remove slf4j-simple-M.m.r.jar from the class path. (I.e.: from pom.xml). As noted, we're talking about multiple bindings at once: just don't do it.

Once you remove it, you probably need to clean your build, e.g.:

$ mvn clean package

...even if you're trying it out in an IDE.


Effect of changes on-the-fly and need to bounce consuming product

If you're using something like Tomcat and you make changes to logging.properties, slf4j.properties, log4j.xml, logback.xml, etc., you'll find that they're not picked up. Not even always after you wait.

In my experience, for example, modifying the log level in logging configuration will never take hold and you must restart the consuming software, like Tomcat.