Why is Logback being configured twice?

I'm trying to switch an application from from log4j to Logback. This app uses SLF4J, Spring Framework and is deployed in Tomcat 7. Spring Framework uses JCL, so I added the following JARs to the application's classpath: slf4j-1.6.1.jar jcl-over-slf4j-1.6.1.jar logback-classic-0.9.29.jar logback-core-0.9.29.jar I created a logback.xml file, with debug="true" so I could debug my configuration. When I deploy this webapp in Tomcat, I can see that Logback is being configured twice. Why would this happen? Thanks in advance, Daniel Serodio

Hello Daniel, Could you please post the contents of your logback.xml file ad well as the output generated by logback on the console? Thanks, On 01/08/2011 10:38 PM, Daniel Serodio (lists) wrote:
I'm trying to switch an application from from log4j to Logback. This app uses SLF4J, Spring Framework and is deployed in Tomcat 7.
Spring Framework uses JCL, so I added the following JARs to the application's classpath:
slf4j-1.6.1.jar jcl-over-slf4j-1.6.1.jar logback-classic-0.9.29.jar logback-core-0.9.29.jar
I created a logback.xml file, with debug="true" so I could debug my configuration.
When I deploy this webapp in Tomcat, I can see that Logback is being configured twice. Why would this happen?
Thanks in advance, Daniel Serodio
-- QOS.ch, main sponsor of cal10n, logback and slf4j open source projects, is looking to hire talented software developers. For further details, see http://logback.qos.ch/job.html

Hello Ceki, This problem wasn't happening anymore, so I compared the logback.xml I'm using now and the one I was using when I posted to the list, and found the source of the problem: an encoding parameter for ConsoleAppender left from log4j configuration. If I remove this line (marked CAUSE below) the problem goes away. Do you think I should I file a bug report? <?xml version="1.0" encoding="UTF-8"?> <configuration debug="true"> <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender" > <param value="UTF-8" name="encoding"/> <!-- CAUSE --> <encoder> <pattern>%d{dd/MM/yyyy HH:mm:ss,SSS} %-5p [%c] %m%n</pattern> </encoder> </appender> <root level="INFO"> <appender-ref ref="CONSOLE"/> </root> </configuration> Thanks, Daniel Serodio Ceki Gülcü wrote:
Hello Daniel,
Could you please post the contents of your logback.xml file ad well as the output generated by logback on the console?
Thanks,
On 01/08/2011 10:38 PM, Daniel Serodio (lists) wrote:
I'm trying to switch an application from from log4j to Logback. This app uses SLF4J, Spring Framework and is deployed in Tomcat 7.
Spring Framework uses JCL, so I added the following JARs to the application's classpath:
slf4j-1.6.1.jar jcl-over-slf4j-1.6.1.jar logback-classic-0.9.29.jar logback-core-0.9.29.jar
I created a logback.xml file, with debug="true" so I could debug my configuration.
When I deploy this webapp in Tomcat, I can see that Logback is being configured twice. Why would this happen?
Thanks in advance, Daniel Serodio

What happens if that line is present? On 04/08/2011 11:01 PM, Daniel Serodio (lists) wrote:
Hello Ceki,
This problem wasn't happening anymore, so I compared the logback.xml I'm using now and the one I was using when I posted to the list, and found the source of the problem: an encoding parameter for ConsoleAppender left from log4j configuration. If I remove this line (marked CAUSE below) the problem goes away.
Do you think I should I file a bug report?
<?xml version="1.0" encoding="UTF-8"?> <configuration debug="true"> <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender" > <param value="UTF-8" name="encoding"/> <!-- CAUSE --> <encoder> <pattern>%d{dd/MM/yyyy HH:mm:ss,SSS} %-5p [%c] %m%n</pattern> </encoder> </appender> <root level="INFO"> <appender-ref ref="CONSOLE"/> </root> </configuration>
Thanks, Daniel Serodio
-- QOS.ch, main sponsor of cal10n, logback and slf4j open source projects, is looking to hire talented software developers. For further details, see http://logback.qos.ch/job.html

Apparently no harm, but I thought that logback getting configured twice would make it unreliable for rolling logs, etc, because of race conditions. In fact, on closer inspection, it seems that it's only the same information being printed twice, because the timestamp of the messages are the same on the first and second ocurrences. In this case, I'm pretty sure it's harmless, although strange. 18:21:38,683 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy] 18:21:38,683 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 18:21:38,710 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/Users/dserodio/Projetos/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/testapp/WEB-INF/classes/logback.xml] 18:21:38,780 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 18:21:38,784 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [CONSOLE] 18:21:38,799 |-WARN in ch.qos.logback.core.joran.util.PropertySetter@4876db09 - No such property [encoding] in ch.qos.logback.core.ConsoleAppender. 18:21:38,802 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 18:21:38,864 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO 18:21:38,864 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[ROOT] 18:21:38,872 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. 18:21:38,683 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy] 18:21:38,683 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 18:21:38,710 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/Users/dserodio/Projetos/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/testapp/WEB-INF/classes/logback.xml] 18:21:38,780 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 18:21:38,784 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [CONSOLE] 18:21:38,799 |-WARN in ch.qos.logback.core.joran.util.PropertySetter@4876db09 - No such property [encoding] in ch.qos.logback.core.ConsoleAppender. 18:21:38,802 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 18:21:38,864 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO 18:21:38,864 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[ROOT] 18:21:38,872 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. Ceki Gülcü wrote:
What happens if that line is present?
On 04/08/2011 11:01 PM, Daniel Serodio (lists) wrote:
Hello Ceki,
This problem wasn't happening anymore, so I compared the logback.xml I'm using now and the one I was using when I posted to the list, and found the source of the problem: an encoding parameter for ConsoleAppender left from log4j configuration. If I remove this line (marked CAUSE below) the problem goes away.
Do you think I should I file a bug report?
<?xml version="1.0" encoding="UTF-8"?> <configuration debug="true"> <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender" > <param value="UTF-8" name="encoding"/> <!-- CAUSE --> <encoder> <pattern>%d{dd/MM/yyyy HH:mm:ss,SSS} %-5p [%c] %m%n</pattern> </encoder> </appender> <root level="INFO"> <appender-ref ref="CONSOLE"/> </root> </configuration>
Thanks, Daniel Serodio
participants (2)
-
Ceki Gülcü
-
Daniel Serodio (lists)