Logback-test.xml configuration is producing two log files instead of one?

Question

When I stop running my spring-boot application there are two log files produced rather than one (one is expected).

What is wrong in my Logback-test.xml file below that may be causing this?

logback-test.xml:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <timestamp key="myTimestamp" datePattern="yyyy-MM-dd'_'HH-mm-ss.SSS"/>

    <include resource="org/springframework/boot/logging/logback/base.xml"/>

    <logger name="org.springframework.web" level="INFO"/>

    <!-- Send debug messages to System.out -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <!-- By default, encoders are assigned the type ch.qos.logback.classic.encoder.PatternLayoutEncoder -->
        <encoder>
            <pattern>%d{HH:mm:ss.SSS}  - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">

        <file>C:\path\to\my\file\myLog-${myTimestamp}.log</file>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <Pattern>%d{yyyy-MM-dd_HH:mm:ss.SSS} - %msg%n</Pattern>
        </encoder>

        <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
            <FileNamePattern>myLog.%i{yyyy-MM-dd_HH:mm:ss.SSS}}.log</FileNamePattern>
            <MinIndex>1</MinIndex>
            <MaxIndex>10</MaxIndex>
        </rollingPolicy>

        <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
            <MaxFileSize>2MB</MaxFileSize>
        </triggeringPolicy>

    </appender>

    <logger name="com.my.package" level="INFO" additivity="false">
        <appender-ref ref="STDOUT" />
        <appender-ref ref="FILE" />
    </logger>

    <!-- By default, the level of the root level is set to DEBUG -->
    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>

</configuration>

The two files being created are e.g.:

myLog-2016-04-22_15-47-30.126.log

and

myLog-2016-04-22_15-47-30.922.log

Answer 1

The timestamp is generated when the configuration is parsed. Since Spring Boot reinitializes logback once during startup, two different timestamps are generated and therefore the two files.

You can use a timeReferene="contextBirth" in your config to get a constant timestamp. Since the LoggerContext isn't destroyed, just resetted this should work:

<timestamp key="myTimestamp" timeReference="contextBirth" datePattern="yyyy-MM-dd'_'HH-mm-ss.SSS"/>

Answer 2

How does your logging.config property look? You problem may be the pathing (or the property missing from your properties file). E.g. should look something like this:

logging.config=classpath:logback-test.xml

in application-test.properties.

The other possibility might be that you have two active profiles. E.g. your test profile and the default one. In that case, you can get around it with conditional configuration in logback.

See the answer for more details. Also, see the last comment on that answer. spring boot 1.3 includes some new features around handling multiple profiles with logback:

http://docs.spring.io/spring-boot/docs/current-SNAPSHOT/reference/htmlsingle/#boot-features-logback-extensions