With the shaded jar from dropwizard I got: Class path contains multiple SLF4J bindings

Question

I probably made something stupid here. There is something (smallish) wrong with my dropwizard setup. Running the shaded jar works fine, but when executing integration tests I get this warning:

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/graphhopper/web/target/graphhopper-web-0.11-SNAPSHOT.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/home/user/.m2/repository/ch/qos/logback/logback-classic/1.2.3/logback-classic-1.2.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [ch.qos.logback.classic.util.ContextSelectorStaticBinder]
INFO  [2018-04-08 18:44:27,653] org.eclipse.jetty.util.log: Logging initialized @1090ms to org.eclipse.jetty.util.log.Slf4jLog

Where graphhopper-web-0.11-SNAPSHOT.jar is the shaded jar with dropwizard (with logback).

This usually means that more than one slf4j binding is on the classpath but I could reject this theory and only slf4j-api is there, plus the logback dependency for dropwizard. I also have analyzed the dependency graph with Netbeans and

mvn dependency:tree -Dverbose -Dincludes=org.slf4j

(see output here) but couldn't find something problematic.

Can it be that the shaded jar (with logback) is somehow put into the classpath with the other jars (including logback) for mvn clean install? How could I avoid this?

Reproduce it via:

git clone https://github.com/graphhopper/graphhopper
cd web
mvn clean install

See this issue.

Have asked this on their forum too https://groups.google.com/forum/#!topic/dropwizard-user/ZDkWUqinzto — Karussell, Apr 24 '18 at 15:12

score 3 · Answer 1 · edited Mar 12 '20 at 17:44

3

imported your code into my intellij community edition, added exclusion as follows to all the dependency in pom.xml of web module. It resolve issues given issue. You may have do changes in respective module.

example:

<dependency>
  <groupId>io.dropwizard</groupId>
  <artifactId>dropwizard-core</artifactId>
  <version>1.2.2</version>
  <exclusions>
    <exclusion>
      <groupId>org.slf4j</groupId>
      <artifactId>slf4j-api</artifactId>
    </exclusion>
  </exclusions>
</dependency>

edited Mar 12 '20 at 17:44

omerhakanbilici

874
1
18
26

answered Apr 26 '18 at 09:36

SantoshPawar

193
5

But won't this break the production code? Obviously the problem is only for integration tests and if I then exclude this dependency for all cases then the production code will break at some point. – Karussell May 15 '18 at 13:22
We to have similar kind of structure in one of our Project.we do it to remove the duplication of jar import and from one module to another module. one more advantage of this is having single copy across the modules. – SantoshPawar May 17 '18 at 18:11

Tarun Lalwani · Answer 2 · 2018-04-26T09:15:10.437

The issue is the jar logback-classic-1.2.3.jar has a actual file /org/slf4j/impl/StaticLoggerBinder.class, so jar exclusion won't work.

You need to change the configuration of the maven-shade-plugin

<configuration>
    <createDependencyReducedPom>true</createDependencyReducedPom>
    <filters>
        <filter>
          <artifact>ch.qos.logback:logback-classic</artifact>
          <excludes>
            <exclude>org/slf4j/impl/**</exclude>
          </excludes>
        </filter>
        <filter>
            <artifact>*:*</artifact>
            <excludes>
                <exclude>META-INF/*.SF</exclude>
                <exclude>META-INF/*.DSA</exclude>
                <exclude>META-INF/*.RSA</exclude>
            </excludes>
        </filter>
    </filters>
</configuration>

Once you do that all is good and the warning is gone

[INFO] Scanning for projects...
[INFO]
[INFO] ------------------< com.graphhopper:graphhopper-web >-------------------
[INFO] Building GraphHopper Web 0.11-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO]
[INFO] --- maven-clean-plugin:2.5:clean (default-clean) @ graphhopper-web ---
[INFO] Deleting /Users/tarun.lalwani/Desktop/tarunlalwani.com/tarunlalwani/workshop/ub16/so/graphhopper/web/target
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ graphhopper-web ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 118 resources
[INFO]
[INFO] --- maven-compiler-plugin:3.5.1:compile (default-compile) @ graphhopper-web ---
[INFO] Changes detected - recompiling the module!
[INFO] Compiling 19 source files to /Users/tarun.lalwani/Desktop/tarunlalwani.com/tarunlalwani/workshop/ub16/so/graphhopper/web/target/classes
[INFO]
[INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ graphhopper-web ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 1 resource
[INFO]
[INFO] --- maven-compiler-plugin:3.5.1:testCompile (default-testCompile) @ graphhopper-web ---
[INFO] Changes detected - recompiling the module!
[INFO] Compiling 9 source files to /Users/tarun.lalwani/Desktop/tarunlalwani.com/tarunlalwani/workshop/ub16/so/graphhopper/web/target/test-classes
[INFO]
[INFO] --- maven-surefire-plugin:2.19.1:test (default-test) @ graphhopper-web ---

-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running com.graphhopper.http.WebHelperTest
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.151 sec - in com.graphhopper.http.WebHelperTest
Running com.graphhopper.http.IPFilterTest
20:29:46.762 [main] DEBUG com.graphhopper.http.IPFilter - whitelist:[4.5.67.1, 1.2.3.4]
20:29:46.765 [main] DEBUG com.graphhopper.http.IPFilter - blacklist:[8.9.7.3]
20:29:46.765 [main] DEBUG com.graphhopper.http.IPFilter - blacklist:[4.5.67.1, 1.2.3.4]
20:29:46.766 [main] DEBUG com.graphhopper.http.IPFilter - whitelist:[4.5.67.1, 1.2.3.4]
20:29:46.766 [main] DEBUG com.graphhopper.http.IPFilter - whitelist:[1.2.3*, 4.5.67.1, 7.8.*.3]
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.003 sec - in com.graphhopper.http.IPFilterTest

Results :

Tests run: 8, Failures: 0, Errors: 0, Skipped: 0

Edit-1: 26-Apr-2018

Updates from https://github.com/graphhopper/graphhopper/issues/1328

I believe the issue is that you run the Dropwizard app integration tests as integration test during the verify phase of the build. This phase gets invoked after the package phase where you create a shaded jar and replace the original jar with it.

[INFO] Replacing original artifact with shaded artifact.
[INFO] Replacing /home/travis/build/graphhopper/graphhopper/web/target/graphhopper-web-0.11-SNAPSHOT.jar with /home/travis/build/graphhopper/graphhopper/web/target/graphhopper-web-0.11-SNAPSHOT-shaded.jar

As a result you have two jars in the classpath with two slf4j bindings (graphhopper-web-0.11-SNAPSHOT and logback-classic-1.2.3.jar). There's no need to create a shaded jar for running an integration test against a Dropwizard application, it can be run as a unit test. So, if you configure graphhopper-web to run its integration tests during the test phase, there will be no warning:

        <plugin>
            <groupId>org.apache.maven.plugins</groupId>
            <artifactId>maven-failsafe-plugin</artifactId>
            <version>2.19.1</version>
            <executions>
                <execution>
                    <goals>
                        <goal>integration-test</goal>
                        <goal>verify</goal>
                    </goals>
                </execution>
            </executions>
            <configuration>
                <excludes>
                    <exclude>com.graphhopper.http.**</exclude>
                </excludes>
            </configuration>
        </plugin>
        <plugin>
            <groupId>org.apache.maven.plugins</groupId>
            <artifactId>maven-surefire-plugin</artifactId>
            <version>2.19.1</version>
            <configuration>
                <argLine>-Xmx100m -Xms100m</argLine>
                <includes>
                    <include>com.graphhopper.http.**</include>
                </includes>
            </configuration>
        </plugin>

Another option is to rename them from *IT to *Test, so they are not automatically matched as integration tests.

Interesting. Thanks. Where is the other StaticLoggerBinder coming from? So logback-classic.jar is kind of a shaded jar itself? — Karussell, Apr 19 '18 at 16:10
@Karussell, the file comes from the same jar to the final uber jar. When that jar is run, something in the tests causes the m2 `logback-classic.jar` also to be loaded. So they are eventually the same files only — Tarun Lalwani, Apr 19 '18 at 19:57
@Karussell, i think the hint is in `SLF4J: Actual binding is of type [ch.qos.logback.classic.util.ContextSelectorStaticBinder]`. The class is using class loader and stuff to load something at run-time and that may be what tries to load the `jar` from maven repository again, causing the conflict — Tarun Lalwani, Apr 20 '18 at 05:54
When using `mvn dependency:tree` it does not list any logback stuff for just test. So this can't be the issue. As the filter applies to the production jar I would like to understand this fully, maybe the test setup is wrong? — Karussell, Apr 23 '18 at 13:19
Run this `mvn dependency:tree -Dincludes=ch.qos.logback*` and you will see logback stuff there — Tarun Lalwani, Apr 23 '18 at 13:35
Of course, dropwizard has a dependency to logback. My point was that there is something in the tests that causes logback to load additionally to the shaded jar and I would like to understand what it is and why. Your suggestion works but the question is: why is this necessary at all? — Karussell, Apr 23 '18 at 13:51
I made a class loader to print all classes being loaded and I think `io/dropwizard/request/logging/RequestLogFactory` might be the root cause here. See [this](https://drive.google.com/open?id=1eTnDtadMx3Z3p6ejIsOzmACcGqPtA30S) — Tarun Lalwani, Apr 24 '18 at 05:10
Oh, wow. Interesting. Thanks. It seems to be that also other classes like URLClassLoader are loaded many times. — Karussell, Apr 24 '18 at 13:11

With the shaded jar from dropwizard I got: Class path contains multiple SLF4J bindings

2 Answers2

Linked