Logback refactored the inclusion of configuration snippets in version 1.5.5. (For details see this commit and this comment in logback repo.)
Updating logback from <= 1.5.4 to >= 1.5.5 breaks <springProperty> when used within an included configuration snippet.
Example
A simple spring boot application using logback.
A prefix for log messages is configured in the environment using <springProperty>.
logback.xml
<configuration>
<include resource="included.xml" optional="false" />
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>${prefix} %msg %n</pattern>
</encoder>
</appender>
<root level="DEBUG">
<appender-ref ref="STDOUT" />
</root>
</configuration>
included.xml
<included>
<!-- works with 1.5.4, broken with 1.5.5 and 1.5.6 -->
<springProperty name="prefix" source="prefix" scope="context" defalultValue="[default prefix]" />
</included>
in application.properties
prefix = [prefix from env]
The expected log output is "[prefix from env] ..." but acutaly is "prefix_IS_UNDEFINED ...".
Cause
Since the refactoring a new instance of JoranConfigurator is created when an inclusion is processed.
new code in JoranConfigurator
private JoranConfigurator makeAnotherInstance() {
JoranConfigurator jc = new JoranConfigurator();
jc.setContext(this.context);
return jc;
}
public void buildModelInterpretationContext() {
super.buildModelInterpretationContext();
this.modelInterpretationContext.setConfiguratorSupplier(() -> {
return this.makeAnotherInstance();
});
}
The new instance is currently not a SpringBootJoranConfigurator but a simple JoranConfigurator that does not know about springs extensions (e.g. <springProperty>).
Therefore <springProfile> might be affected as well.
Fix
Overriding buildModelInterpretationContext() in SpringBootJoranConfigurator to provide an instance of SpringBootJoranConfigurator with the same LoggingInitializationContext.
Comment From: fupgang
The bug affects 3.3.0-RC1 that uses logback 1.5.6 (see https://github.com/spring-projects/spring-boot/issues/40401).
Spring boot 3.2.5 uses version 1.4.14 of logback, the issue arises when manually upgrade to logback >= 1.5.5.
Comment From: mhalbritter
Hey, thanks for the report. Can you please attach your sample project as something we can clone or unzip? Thanks!
Comment From: fupgang
Comment From: scottfrederick
Thanks for the sample @fupgang.
The Spring Boot documentation states that a file logback-spring.xml should be used to configure Logback instead of logback.xml when Spring extensions are used. That doesn't fix the problem, but the correct file name should be used once this issue is resolved.
Spring Boot adds the springProperty extension rule using the path configuration/springProperty:
https://github.com/spring-projects/spring-boot/blob/d534204a3674cb1f255d50b57ccd6dc825cf1677/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/SpringBootJoranConfigurator.java#L103-L108
Logback's SimpleRuleStore.matchActions(ElementPath elementPath) will be called when the springProperty element is encountered in included.xml using the provided sample.
When using Logback 1.5.4 and earlier, matchActions gets a path [configuration][springProperty], the lookup succeeds, and the prefix property is resolved.
When using Logback 1.5.5 and later, matchActions gets a path [included][springProperty], the lookup fails, and the prefix property is not resolved.
Spring Boot might be able to address this by adding springProperty with a path like */springProperty as we do with springProfile.
@ceki Was this change in lookup paths intended as part of the changes mentioned above in Logback 1.5.5 and 1.5.6?
Comment From: ceki
@scottfrederick I think the analysis provided by @fupgang is quite accurate.
The key phrase is:
Since the refactoring a new instance of JoranConfigurator is created when an inclusion is processed.
IncludeModelHandler (new in logback 1.5.5) reads the included XML file and transforms it to a model using a new configurator instance provided by a supplier set in ModelInterpretationContext.
The fix suggested by @fupgang seems quite appropriate. Indeed, the default configurator supplier will return an instance of JoranConfigurator instead of SpringBootJoranConfigurator. JoranConfigurator is unaware of <springProperty>.
As for the matchActions, IncludeModelHandler adds a mapping replacing "includes" path-part with "configuration" path-part which should be fine as well.
In short, overriding buildModelInterpretationContext in SpringBootJoranConfigurator is the way to go.
Perhaps something like:
class SpringBootJoranConfigurator extends JoranConfigurator {
private SpringBootJoranConfigurator makeAnotherSpringBootConfiguratorInstance() {
SpringBootJoranConfigurator sbjc = new SpringBootJoranConfigurator();
sbjc.setContext(this.context);
return sbjc;
}
public void buildModelInterpretationContext() {
super.buildModelInterpretationContext();
this.modelInterpretationContext.setConfiguratorSupplier(() -> {
return this.makeAnotherSpringBootConfiguratorInstance();
});
}