-Dlogback.configurationFile=logback.xml ignored when running Spring-Boot

Question

We have a spring-boot 1.0.RC1 application, with logback configured for logging and a logback.xml file in src/test/resources. When we run spring-boot from maven, the logback file seems to be seen and respected. (That's our required logging format after the spring-boot logo)

D:\Users\myName\My Projects\Work\my-co\my-app\src\my-app\my-app-camel>mvn  clean spring-boot:run -Dlogback.statusListenerClass=ch.qos.logback.core.status.OnConsoleStatusListener -Dlogback.configurationFile=src/test/resources/logback.xml

<snip/>

[INFO] --- spring-boot-maven-plugin:0.5.0.M7:run (default-cli) @ my-app-camel ---
06:41:56,011 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [src/test/resources/logback.xml] at [file:/D:/Users/myName/My%20Projects/Work/my-co/my-app/src/my-app/my-app-camel/src/test/resources/logback.xml]
06:41:56,150 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
06:41:56,170 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Setting ReconfigureOnChangeFilter scanning period to 5 seconds
06:41:56,171 |-INFO in ReconfigureOnChangeFilter{invocationCounter=0} - Will scan for changes in [[D:\Users\myName\My Projects\Work\my-co\my-app\src\my-app\my-app-camel\src\test\resources\logback.xml]] every 5 seconds.
06:41:56,172 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Adding ReconfigureOnChangeFilter as a turbo filter
06:41:56,223 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
06:41:56,233 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
06:41:56,276 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
06:41:56,389 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [me.moocar.logbackgelf.GelfAppender]
06:41:56,398 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [GELF]
06:41:56,567 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.my-co.my-app.] to DEBUG
06:41:56,568 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.my-co.my-app.] to false
06:41:56,569 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[com.my-co.my-app.]
06:41:56,571 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.] to DEBUG
06:41:56,572 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org.] to false
06:41:56,572 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[org.]
06:41:56,573 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
06:41:56,574 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
06:41:56,574 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
06:41:56,578 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@4ffdcca5 - Registering current configuration as safe fallback point

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::            (v1.0.0.RC1)

06:41:57.436 [com.my-co.my-app.Application.main()] INFO  com.my-co.my-app.Application - Starting Application on MY-LAPTOP-HOSTNAME with PID 7812 (started by myName)
06:41:57.952 [com.my-co.my-app.Application.main()] INFO  o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [META-INF/spring/camel-server.xml]

<etc./>

However, when we remove a rogue logback.xml file which snuck into src/java/resources and re-run with everything else unchanged (making sure we clean to remove the one in target too):

D:\Users\myName\My Projects\Work\my-co\my-app\src\my-app\my-app-camel>mvn  clean spring-boot:run -Dlogback.statusListenerClass=ch.qos.logback.core.status.OnConsoleStatusListener -Dlogback.configurationFile=src/test/resources/logback.xml

<snip/>

[INFO]
[INFO] <<< spring-boot-maven-plugin:1.0.0.RC1:run (default-cli) @ my-app-camel <<<
[INFO]
[INFO] --- spring-boot-maven-plugin:1.0.0.RC1:run (default-cli) @ my-app-camel ---
06:53:59,598 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [src/test/resources/logback.xml] at [file:/D:/Users/myName/My%20Projects/Work/my-co/my-app/src/my-app/my-app-camel/src/test/resources/logback.xml]
06:53:59,736 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
06:53:59,755 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Setting ReconfigureOnChangeFilter scanning period to 5 seconds
06:53:59,756 |-INFO in ReconfigureOnChangeFilter{invocationCounter=0} - Will scan for changes in [[D:\Users\myName\My Projects\Work\my-co\my-app\src\my-app\my-app-camel\src\test\resources\logback.xml]] every 5 seconds.
06:53:59,757 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Adding ReconfigureOnChangeFilter as a turbo filter
06:53:59,806 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
06:53:59,817 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
06:53:59,858 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
06:53:59,971 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [me.moocar.logbackgelf.GelfAppender]
06:53:59,980 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [GELF]
06:54:00,144 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.my-co.my-app.] to DEBUG
06:54:00,144 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.my-co.my-app.] to false
06:54:00,145 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[com.my-co.my-app.]
06:54:00,148 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.] to DEBUG
06:54:00,148 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org.] to false
06:54:00,149 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[org.]
06:54:00,150 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG
06:54:00,150 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
06:54:00,151 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
06:54:00,154 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@54c1f582 - Registering current configuration as safe fallback point

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::            (v1.0.0.RC1)

2014-02-12 06:54:01.023  INFO 5240 --- [lication.main()] com.my-co.my-app.Application          : Starting Application on MY-LAPTOP-HOSTNAME with PID 5240 (started by myName)
2014-02-12 06:54:01.564  INFO 5240 --- [lication.main()] o.s.b.f.xml.XmlBeanDefinitionReader      : Loading XML bean definitions from class path resource [META-INF/spring/camel-server.xml]

<etc./>

You'll notice that the logging format after spring-boot starts is different from the first output. However, logback (prior to Spring-Boot starting) reports it's seen the logback.xml in src/test/resources, just like it did the first time.

For interest, our logback.xml (which was in both src/java/resources and src/test/resources is as follows:

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="5 seconds">

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{40} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="GELF" class="me.moocar.logbackgelf.GelfAppender">
        <facility>logback-gelf-test</facility>
        <graylog2ServerHost>XXX.XXX.XXX.XXX</graylog2ServerHost>
        <graylog2ServerPort>NNNNN</graylog2ServerPort>
        <useLoggerName>true</useLoggerName>
        <useThreadName>true</useThreadName>
        <useMarker>true</useMarker>
        <graylog2ServerVersion>0.9.6</graylog2ServerVersion>
        <chunkThreshold>1000</chunkThreshold>
        <messagePattern>%m%rEx</messagePattern>
        <shortMessagePattern>%.-100(%m%rEx)</shortMessagePattern>
        <additionalField>ipAddress:_ip_address</additionalField>
        <additionalField>requestId:_request_id</additionalField>
        <staticAdditionalField>_node_name:www013</staticAdditionalField>
        <includeFullMDC>true</includeFullMDC>
    </appender>

    <logger name="com.my-co.my-app." level="DEBUG" additivity="false">
        <appender-ref ref="STDOUT" />
    </logger>

    <logger name="org." level="DEBUG" additivity="false">
        <appender-ref ref="STDOUT" />
    </logger>

    <root level="INFO">
        <appender-ref ref="STDOUT" />
        <!--<appender-ref ref="GELF" />-->
    </root>

</configuration>

So in summary, it seems (though I might be wrong) that when a logback.xml is bundled with my spring-boot app it is seen and used (i.e. in src/java/resources), but when we don't bundle, then despite logback's best efforts it's ignored.

As for fixing this, we're stumped. We're guessing that there is something somewhere in our spring-boot jar which is somehow taking precedence, or turning off logback, or stepping in and telling logback to ignore what it's just been told and to use another default.

Alternatively we're being dumb, but can't see it. All help gratefully received.

Answer 1

The default strategy assumes that if you don't have a logback.xml (or one of the other standard file names) in the classpath then you must be happy with the defaults (see LogbackLoggingSystem for details). Spring Boot tries to unify the external configuration switches for common logging sytems, so it looks in logging.config (it didn't know about logback.configurationFile). You could use that instead (i.e. logging.config=file:./src/test/resources/logback.xml), or make sure your config file is on the classpath.

Answer 2

I know this post is a bit old but adding the following to application.properties is a quick workaround based on Dave Syer's answer:

logging.config=${logback.configurationFile}

Answer 3

According to Spring Boot documentation, you could run like this:

java -jar app.jar --logging.config=./src/test/resources/logback.xml

Additionally, Spring Boot tries to unify the properties name of the different log startegies. As a result, the JVM parameter Dlogback.configurationFile is not used for Spring Boot.

Answer 4

If logback xml is under resources folder, you can add following to VM option:

java -jar App.jar -Dlogging.config=classpath:logback-local.xml

Answer 5

Add logback file path in application.properties file . Example test folder contains app.jar and config folder as below
test
|- app.jar
|- config
        |--- application.properties
        |--- logback.xml

Then add logging.config:config\\logback.xml. Then try , it will work

Answer 6

Assuming you have spring logback configurations in config directory, the command below will add external file by overriding the existing file (if any) inside the application:

java -jar -Dlogging.config=./config/logback-spring.xml app.jar --spring.config.location=./config/application.properties

Answer 7

Not quite right. logback.configurationFile is not managed by Spring (i.e. env var replacement or so), but logback will still pick it up. At least that's my understanding of the docs and my practical experience.