Details
-
Bug
-
Resolution: Fixed
-
Major
-
1.4.6
-
spring boot application 3.x.x
Description
We are migration from Logback 1.2.11 to 1.4.7 and stumbled upon some log pollution. When a <include> element is used the and it is not able to resolve the file two entries are added to the log.
11:00:18,521 |-INFO in ch.qos.logback.core.joran.util.ConfigurationWatchListUtil@43ed0ff3 - Adding [file:/C:/dev/include_IS_UNDEFINED] to configuration watch list. 11:00:18,522 |-WARN in ch.qos.logback.core.joran.action.IncludeAction - Failed to open [file:/C:/dev/include_IS_UNDEFINED]
This is correct as the variable is currently undefined and logback is not able to include it yet. So yes I would expect to see these statement in the log.
However when placing an <include> element inside an <if> block I would not expect these statement to be included, as it should try to read the configuration.
Reproduction configuration:
<configuration debug="true"> <!-- I placed the variable on the scope "system" as this is another bug. https://jira.qos.ch/browse/LOGBACK-1731 --> <variable scope="system" name="include" value="C:/dev/include.xml"/> <if condition='isDefined("include")'> <then> <include file="${include}"/> </then> </if> </configuration>
Using the following configuration will result into the following log statements:
11:15:44,779 |-INFO in ch.qos.logback.core.joran.util.ConfigurationWatchListUtil@6de54b40 - Adding [file:/C:/dev/include_IS_UNDEFINED] to configuration watch list. 11:15:44,779 |-WARN in ch.qos.logback.core.joran.action.IncludeAction - Failed to open [file:/C:/dev/include_IS_UNDEFINED] 11:15:45,593 |-INFO in ch.qos.logback.core.model.processor.conditional.IfModelHandler - Condition [isDefined("include")] evaluated to true on line 3
What we have noticed is that the IncludeAction is processed before the variable is set. I would expect that the <include> element is only processed when the condition has been met.
In the first line we see that <include> element is already being processed before the Condition or Variable have been processed.
Now in the second line it is trying to open the file which it can't.
On the third line we can see that the Condition actually is succeeding as the Variable has now been processed.
Expectations:
I would expect that the IncludeAction would take place in the order of definition:
- Variable "include" is set
- If condition is processed and matches
- File include is executed
But what we see is the following:
- File include is executed
- Variable "include" is set
- If condition is processed and matches
This would result into lesser log statements,
Attachments
Issue Links
- relates to (out)
-
LOGBACK-1731 <include> element only seems to be substituting variables which are on scope "system"
- Resolved
-
LOGBACK-1746 insertFromJNDI resolves AFTER include in 1.4.x
- Resolved
- links to