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

SpringLogbackSpring Boot

Spring Problem Overview


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.

Spring Solutions


Solution 1 - Spring

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.

Solution 2 - Spring

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}

Solution 3 - Spring

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.

Solution 4 - Spring

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

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

Solution 5 - Spring

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

Solution 6 - Spring

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

Solution 7 - Spring

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.

Attributions

All content for this solution is sourced from the original question on Stackoverflow.

The content on this page is licensed under the Attribution-ShareAlike 4.0 International (CC BY-SA 4.0) license.

Content TypeOriginal AuthorOriginal Content on Stackoverflow
QuestionAndrew Harmel-LawView Question on Stackoverflow
Solution 1 - SpringDave SyerView Answer on Stackoverflow
Solution 2 - SpringltalhouarneView Answer on Stackoverflow
Solution 3 - SpringjmgoyescView Answer on Stackoverflow
Solution 4 - Springsendon1982View Answer on Stackoverflow
Solution 5 - Springuser3172374View Answer on Stackoverflow
Solution 6 - SpringBilal Ahmed YaseenView Answer on Stackoverflow
Solution 7 - Springuser625488View Answer on Stackoverflow