Issue with LoggerFactory on Java 9

Hello. It seems that LoggerFactory misbehaves when used from a modular project: I have a very simple repro case here: https://github.com/io7m/logback-bug-20180209 The error is: Exception in thread "main" java.util.ServiceConfigurationError: ch.qos.logback.classic.spi.Configurator: module ch.qos.logback.classic does not declare `uses` at java.base/java.util.ServiceLoader.fail(ServiceLoader.java:588) at java.base/java.util.ServiceLoader.checkCaller(ServiceLoader.java:574) at java.base/java.util.ServiceLoader.<init>(ServiceLoader.java:503) at java.base/java.util.ServiceLoader.load(ServiceLoader.java:1639) at ch.qos.logback.classic/ch.qos.logback.classic.util.EnvUtil.loadFromServiceLoader(EnvUtil.java:48) at ch.qos.logback.classic/ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:155) at ch.qos.logback.classic/ch.qos.logback.classic.spi.LogbackServiceProvider.initializeLoggerContext(LogbackServiceProvider.java:49) at ch.qos.logback.classic/ch.qos.logback.classic.spi.LogbackServiceProvider.initialize(LogbackServiceProvider.java:40) at org.slf4j/org.slf4j.LoggerFactory.bind(LoggerFactory.java:153) at org.slf4j/org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:141) at org.slf4j/org.slf4j.LoggerFactory.getProvider(LoggerFactory.java:419) at org.slf4j/org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:405) at org.slf4j/org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:354) at org.slf4j/org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:380) at com.io7m.bugs.logback/com.io7m.bugs.logback.Main.<clinit>(Main.java:8) The code simply calls: private static final Logger LOG = LoggerFactory.getLogger(Main.class); ... with a module descriptor: module com.io7m.bugs.logback { requires org.slf4j; } -- Mark Raynsford | http://www.io7m.com

Hi Mark, After downloading your project from Github to the logback-io7 foder, I created a lib subfolder and copied logback-*-1.3.0-alpha2.jar and slf4j-api-1.8.0-beta1.jar to that lib directory I then ran (9) camel ~/logback-io7 >java $ST -cp 'target/logback-20180209-1.0.0.jar;lib/logback-core-1.3.0-alpha2.jar;lib/logback-classic-1.3.0-alpha2.jar;lib/slf4j-api-1.8.0-beta1.jar' com.io7 m.bugs.logback.Main with ST variable defined as ST="-Dlogback.statusListenerClass=ch.qos.logback.core.status.OnConsoleStatusListener" Running the above command resulted in 18:28:21,723 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 18:28:21,754 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy] 18:28:21,770 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.xml] 18:28:21,770 |-INFO in ch.qos.logback.classic.BasicConfigurator@6321e813 - Setting up default configuration. 18:28:21.785 [main] DEBUG com.io7m.bugs.logback.Main - hello It all looks good to me. BTW, I am running Java version 9.0.1. -- Ceki On 09.02.2018 17:36, Mark Raynsford wrote:
Hello.
It seems that LoggerFactory misbehaves when used from a modular project:
I have a very simple repro case here:
https://github.com/io7m/logback-bug-20180209
The error is:
Exception in thread "main" java.util.ServiceConfigurationError: ch.qos.logback.classic.spi.Configurator: module ch.qos.logback.classic does not declare `uses` at java.base/java.util.ServiceLoader.fail(ServiceLoader.java:588) at java.base/java.util.ServiceLoader.checkCaller(ServiceLoader.java:574) at java.base/java.util.ServiceLoader.<init>(ServiceLoader.java:503) at java.base/java.util.ServiceLoader.load(ServiceLoader.java:1639) at ch.qos.logback.classic/ch.qos.logback.classic.util.EnvUtil.loadFromServiceLoader(EnvUtil.java:48) at ch.qos.logback.classic/ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:155) at ch.qos.logback.classic/ch.qos.logback.classic.spi.LogbackServiceProvider.initializeLoggerContext(LogbackServiceProvider.java:49) at ch.qos.logback.classic/ch.qos.logback.classic.spi.LogbackServiceProvider.initialize(LogbackServiceProvider.java:40) at org.slf4j/org.slf4j.LoggerFactory.bind(LoggerFactory.java:153) at org.slf4j/org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:141) at org.slf4j/org.slf4j.LoggerFactory.getProvider(LoggerFactory.java:419) at org.slf4j/org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:405) at org.slf4j/org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:354) at org.slf4j/org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:380) at com.io7m.bugs.logback/com.io7m.bugs.logback.Main.<clinit>(Main.java:8)
The code simply calls:
private static final Logger LOG = LoggerFactory.getLogger(Main.class);
... with a module descriptor:
module com.io7m.bugs.logback { requires org.slf4j; }
_______________________________________________ logback-user mailing list logback-user@qos.ch http://mailman.qos.ch/mailman/listinfo/logback-user
-- -- Ceki Gülcü

On 2018-02-09T18:35:47 +0100 Ceki <ceki@qos.ch> wrote:
Hi Mark,
After downloading your project from Github to the logback-io7 foder, I created a lib subfolder and copied logback-*-1.3.0-alpha2.jar and slf4j-api-1.8.0-beta1.jar to that lib directory
I then ran
(9) camel ~/logback-io7 >java $ST -cp 'target/logback-20180209-1.0.0.jar;lib/logback-core-1.3.0-alpha2.jar;lib/logback-classic-1.3.0-alpha2.jar;lib/slf4j-api-1.8.0-beta1.jar' com.io7 m.bugs.logback.Main
with ST variable defined as
ST="-Dlogback.statusListenerClass=ch.qos.logback.core.status.OnConsoleStatusListener"
Running the above command resulted in
18:28:21,723 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 18:28:21,754 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy] 18:28:21,770 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.xml] 18:28:21,770 |-INFO in ch.qos.logback.classic.BasicConfigurator@6321e813 - Setting up default configuration. 18:28:21.785 [main] DEBUG com.io7m.bugs.logback.Main - hello
It all looks good to me. BTW, I am running Java version 9.0.1.
I think the jars need to be on the module path (as opposed to the classpath) to trigger the problem. I've added a run.sh script to the repos that should be executed after "mvn package". Essentially, it does this: cp $HOME/.m2/repository/org/slf4j/slf4j-api/1.8.0-beta1/slf4j-api-1.8.0-beta1.jar target cp $HOME/.m2/repository/ch/qos/logback/logback-classic/1.3.0-alpha2/logback-classic-1.3.0-alpha2.jar target cp $HOME/.m2/repository/ch/qos/logback/logback-core/1.3.0-alpha2/logback-core-1.3.0-alpha2.jar target rm -rf target/classes java --module-path target --module com.io7m.bugs.logback/com.io7m.bugs.logback.Main This gives me: $ ./run.sh + cp /home/someone/.m2/repository/org/slf4j/slf4j-api/1.8.0-beta1/slf4j-api-1.8.0-beta1.jar target + cp /home/someone/.m2/repository/ch/qos/logback/logback-classic/1.3.0-alpha2/logback-classic-1.3.0-alpha2.jar target + cp /home/someone/.m2/repository/ch/qos/logback/logback-core/1.3.0-alpha2/logback-core-1.3.0-alpha2.jar target + rm -rf target/classes + java --module-path target --module com.io7m.bugs.logback/com.io7m.bugs.logback.Main Exception in thread "main" java.util.ServiceConfigurationError: ch.qos.logback.classic.spi.Configurator: module ch.qos.logback.classic does not declare `uses` at java.base/java.util.ServiceLoader.fail(ServiceLoader.java:588) at java.base/java.util.ServiceLoader.checkCaller(ServiceLoader.java:574) at java.base/java.util.ServiceLoader.<init>(ServiceLoader.java:503) at java.base/java.util.ServiceLoader.load(ServiceLoader.java:1639) at ch.qos.logback.classic/ch.qos.logback.classic.util.EnvUtil.loadFromServiceLoader(EnvUtil.java:48) at ch.qos.logback.classic/ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:155) at ch.qos.logback.classic/ch.qos.logback.classic.spi.LogbackServiceProvider.initializeLoggerContext(LogbackServiceProvider.java:49) at ch.qos.logback.classic/ch.qos.logback.classic.spi.LogbackServiceProvider.initialize(LogbackServiceProvider.java:40) at org.slf4j/org.slf4j.LoggerFactory.bind(LoggerFactory.java:153) at org.slf4j/org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:141) at org.slf4j/org.slf4j.LoggerFactory.getProvider(LoggerFactory.java:419) at org.slf4j/org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:405) at org.slf4j/org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:354) at org.slf4j/org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:380) at com.io7m.bugs.logback/com.io7m.bugs.logback.Main.<clinit>(Main.java:8) $ java -version openjdk version "9" OpenJDK Runtime Environment (build 9+181) OpenJDK 64-Bit Server VM (build 9+181, mixed mode) -- Mark Raynsford | http://www.io7m.com
participants (2)
-
Ceki
-
Mark Raynsford