Dan Groves created LOGBACK-1478:
-----------------------------------

             Summary: LogServiceProvider.initialize called twice
                 Key: LOGBACK-1478
                 URL: https://jira.qos.ch/browse/LOGBACK-1478
             Project: logback
          Issue Type: Bug
    Affects Versions: 1.3.0-alpha4
            Reporter: Dan Groves
            Assignee: Logback dev list
         Attachments: logback-demo.tar

With logback 1.3.0-alpha code and slf4j 1.8, {{LogServiceProvider::initialize}} 
can be called twice.  I did not see this with logback 1.2.3 and slf4j 1.7.25.

I attached some test code.  The test code uses logback 1.3.0-alpha4, but I saw 
the problem with all alpha versions of logback 1.3.0.

{noformat}
$ tar xf logback-demo.tar
$ cd logback-demo
$ ./gradlew clean build

BUILD SUCCESSFUL in 0s
8 actionable tasks: 7 executed, 1 up-to-date
$ cd build/distributions
$ tar xf logback-demo-1.0-SNAPSHOT.tar
$ cd logback-demo-1.0-SNAPSHOT/bin/
$ ./logback-demo
16:30:12,127 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could 
NOT find resource [logback-test.xml]
16:30:12,127 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could 
NOT find resource [logback.groovy]
16:30:12,127 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found 
resource [logback.xml] at 
[jar:file:/Users/dgroves/git/demo/logback-demo/build/distributions/logback-demo-1.0-SNAPSHOT/lib/logback-demo-1.0-SNAPSHOT.jar!/logback.xml]
16:30:12,140 |-INFO in 
ch.qos.logback.core.joran.spi.ConfigurationWatchList@ee7d9f1 - URL 
[jar:file:/Users/dgroves/git/demo/logback-demo/build/distributions/logback-demo-1.0-SNAPSHOT/lib/logback-demo-1.0-SNAPSHOT.jar!/logback.xml]
 is not of type file
16:30:12,202 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About 
to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
16:30:12,205 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming 
appender as [STDOUT]
16:30:12,210 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA 
- Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] 
for [encoder] property
16:30:12,230 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - 
Setting level of ROOT logger to DEBUG
16:30:12,230 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - 
Attaching appender named [STDOUT] to Logger[ROOT]
16:30:12,231 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction 
- End of configuration.
16:30:12,232 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@18ef96 - 
Registering current configuration as safe fallback point
16:30:12.233 [main] INFO  demo - test
16:30:12,235 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could 
NOT find resource [logback-test.xml]
16:30:12,235 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could 
NOT find resource [logback.groovy]
16:30:12,235 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found 
resource [logback.xml] at 
[jar:file:/Users/dgroves/git/demo/logback-demo/build/distributions/logback-demo-1.0-SNAPSHOT/lib/logback-demo-1.0-SNAPSHOT.jar!/logback.xml]
16:30:12,235 |-INFO in 
ch.qos.logback.core.joran.spi.ConfigurationWatchList@17ed40e0 - URL 
[jar:file:/Users/dgroves/git/demo/logback-demo/build/distributions/logback-demo-1.0-SNAPSHOT/lib/logback-demo-1.0-SNAPSHOT.jar!/logback.xml]
 is not of type file
16:30:12,237 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About 
to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
16:30:12,238 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming 
appender as [STDOUT]
16:30:12,238 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA 
- Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] 
for [encoder] property
16:30:12,239 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - 
Setting level of ROOT logger to DEBUG
16:30:12,239 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - 
Attaching appender named [STDOUT] to Logger[ROOT]
16:30:12,239 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction 
- End of configuration.
16:30:12,239 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@50675690 
- Registering current configuration as safe fallback point
{noformat}

If I modify the {{build.gradle}} file in the bundle to comment out the newer 
dependencies and instead use the older ones, so that the dependencies block 
looks like:

{noformat}
dependencies {
    implementation "org.jetbrains.kotlin:kotlin-stdlib-jdk8"

    // These cause the double call into LogbackServiceProvider.initialize
    // implementation "org.slf4j:slf4j-api:1.8.0-beta4"
    // implementation "ch.qos.logback:logback-classic:1.3.0-alpha4"

    // These do not cause the double call into LogbackServiceProvider.initialize
    implementation "org.slf4j:slf4j-api:1.7.25"
    implementation "ch.qos.logback:logback-classic:1.2.3"
}

{noformat}

I get different output showing only one attempt to initialize logback:

{noformat}
$ ./gradlew clean build

BUILD SUCCESSFUL in 0s
8 actionable tasks: 7 executed, 1 up-to-date
$ cd build/distributions/
$ tar xf logback-demo-1.0-SNAPSHOT.tar 
$ cd logback-demo-1.0-SNAPSHOT/bin/
$ ./logback-demo
16:34:05,882 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could 
NOT find resource [logback-test.xml]
16:34:05,882 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could 
NOT find resource [logback.groovy]
16:34:05,882 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found 
resource [logback.xml] at 
[jar:file:/Users/dgroves/git/demo/logback-demo/build/distributions/logback-demo-1.0-SNAPSHOT/lib/logback-demo-1.0-SNAPSHOT.jar!/logback.xml]
16:34:05,894 |-INFO in 
ch.qos.logback.core.joran.spi.ConfigurationWatchList@ba8a1dc - URL 
[jar:file:/Users/dgroves/git/demo/logback-demo/build/distributions/logback-demo-1.0-SNAPSHOT/lib/logback-demo-1.0-SNAPSHOT.jar!/logback.xml]
 is not of type file
16:34:05,960 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About 
to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
16:34:05,963 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming 
appender as [STDOUT]
16:34:05,967 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA 
- Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] 
for [encoder] property
16:34:05,988 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - 
Setting level of ROOT logger to DEBUG
16:34:05,988 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - 
Attaching appender named [STDOUT] to Logger[ROOT]
16:34:05,988 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction 
- End of configuration.
16:34:05,989 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@4ca8195f 
- Registering current configuration as safe fallback point
16:34:05.991 [main] INFO  demo - test

{noformat}





--
This message was sent by Atlassian JIRA
(v7.3.1#73012)
_______________________________________________
logback-dev mailing list
logback-dev@qos.ch
http://mailman.qos.ch/mailman/listinfo/logback-dev

Reply via email to