Search code examples
javaspring-bootlogbackslf4jspring-logback

Logback with SpringProfile generating 2 files


I'm trying to use logback-spring.xml with springprofile as below, this is a custom logging dependency goes into services, when I activate common-services profile I got 2 logs generated, while based on the config below 1 file should be generated, can anyone tell me what's wrong?

 <?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <property resource="bootstrap.yml" />
    <springProperty name="appName"
        source="spring.application.name" />
    <springProperty name="loglevel"
        source="logging.level.com.cialty" />
    <springProperty name="serverPort" source="server.port" />

    <appender name="CONSOLE"
        class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{ISO8601} %-5p [%c{3}] [%t] %m%n</pattern>
        </encoder>
    </appender>

    <appender name="APPLICATION"
        class="ch.qos.logback.core.rolling.RollingFileAppender">
        <springProfile name="common-services">
            <file>/appllogs/spp/${appName}-${serverPort}.log</file>
        </springProfile>
        <springProfile name="default">
            <file>/appllogs/spp/${appName}.log</file>
        </springProfile>
        <rollingPolicy
            class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

            <springProfile name="common-services">
                <fileNamePattern>/appllogs/backup/${appName}/%d{yyyy-MM-dd}%i.log-${serverPort}.zip
                </fileNamePattern>
            </springProfile>
            <springProfile name="default">
                <fileNamePattern>/appllogs/backup/${appName}/%d{yyyy-MM-dd}%i.log.zip
                </fileNamePattern>
            </springProfile>
            <maxHistory>7</maxHistory>
            <timeBasedFileNamingAndTriggeringPolicy
                class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>500MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <totalSizeCap>1GB</totalSizeCap>
        </rollingPolicy>

        <encoder>
            <pattern>%d %-5p %m%n</pattern>
        </encoder>
    </appender>
    
    <logger name="org.springframework.cloud" level="ERROR"
        additivity="false">
        <appender-ref ref="CONSOLE" />
    </logger>
    <logger name="com.cialty" level="${loglevel}"
        additivity="false">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="APPLICATION" />
    </logger>

    <root level="${loglevel}">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="APPLICATION" />
    </root>
</configuration>

UPDATE: Logs added

08:01:46,061 |-WARN in Logger[org.springframework.core.env.PropertySourcesPropertyResolver] - No appenders present in context [default] for logger [org.springframework.core.env.PropertySourcesPropertyResolver].
08:01:46,062 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
08:01:46,062 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [CONSOLE]
08:01:46,066 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
08:01:46,079 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
08:01:46,081 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [APPLICATION]
08:01:46,089 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1641672672 - setting totalSizeCap to 1 GB
08:01:46,091 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1641672672 - Will use zip compression
08:01:46,092 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1641672672 - Will use the pattern /appllogs/backup/specialty-redis-schedule/%d{yyyy-MM-dd}%i.log-8443 for the active file
08:01:46,094 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7e094740 - The date pattern is 'yyyy-MM-dd' from file name pattern '/appllogs/backup/specialty-redis-schedule/%d{yyyy-MM-dd}%i.log-8443.zip'.
08:01:46,094 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7e094740 - Roll-over at midnight.
08:01:46,095 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7e094740 - Setting initial period to Wed Aug 05 08:01:46 CDT 2020
08:01:46,095 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7e094740 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
08:01:46,095 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7e094740 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
08:01:46,097 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
08:01:46,098 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[APPLICATION] - Active log file name: /appllogs/spp/specialty-redis-schedule-8443.log
08:01:46,098 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[APPLICATION] - File property is set to [/appllogs/spp/specialty-redis-schedule-8443.log]
08:01:46,100 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.springframework.cloud] to OFF
08:01:46,100 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@1ac85b0c - Propagating OFF level on Logger[org.springframework.cloud] onto the JUL framework
08:01:46,101 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[org.springframework.cloud]
08:01:46,101 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [APPLICATION] to Logger[org.springframework.cloud]
08:01:46,101 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.cialty] to INFO
08:01:46,101 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@1ac85b0c - Propagating INFO level on Logger[com.cialty] onto the JUL framework
08:01:46,101 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.cialty] to false
08:01:46,101 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[com.cialty]
08:01:46,101 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [APPLICATION] to Logger[com.cialty]
08:01:46,101 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
08:01:46,104 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@1ac85b0c - Propagating INFO level on Logger[ROOT] onto the JUL framework
08:01:46,104 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[ROOT]
08:01:46,104 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [APPLICATION] to Logger[ROOT]
08:01:46,104 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
08:01:46,104 |-INFO in org.springframework.boot.logging.logback.SpringBootJoranConfigurator@16fb356 - Registering current configuration as safe fallback point
2020-08-05 08:01:46,597 INFO  [o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker] [main] Bean 'org.springframework.retry.annotation.RetryConfiguration' of type [org.springframework.retry.annotation.RetryConfiguration$$EnhancerBySpringCGLIB$$85af8ffe] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
08:01:47,923 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
08:01:47,923 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [CONSOLE]
08:01:47,923 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
08:01:47,924 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
08:01:47,924 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [APPLICATION]
08:01:47,925 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@691540605 - setting totalSizeCap to 1 GB
08:01:47,926 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@691540605 - Will use zip compression
08:01:47,926 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@691540605 - Will use the pattern /appllogs/backup/specialty-redis-schedule/%d{yyyy-MM-dd}%i.log for the active file
08:01:47,926 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@127a7272 - The date pattern is 'yyyy-MM-dd' from file name pattern '/appllogs/backup/specialty-redis-schedule/%d{yyyy-MM-dd}%i.log.zip'.
08:01:47,926 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@127a7272 - Roll-over at midnight.
08:01:47,927 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@127a7272 - Setting initial period to Wed Aug 05 08:01:47 CDT 2020
08:01:47,927 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@127a7272 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
08:01:47,927 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@127a7272 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
08:01:47,928 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
08:01:47,928 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[APPLICATION] - Active log file name: /appllogs/spp/specialty-redis-schedule.log
08:01:47,929 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[APPLICATION] - File property is set to [/appllogs/spp/specialty-redis-schedule.log]
08:01:47,930 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.springframework.cloud] to OFF
08:01:47,930 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@ff23ae7 - Propagating OFF level on Logger[org.springframework.cloud] onto the JUL framework
08:01:47,930 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[org.springframework.cloud]
08:01:47,930 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [APPLICATION] to Logger[org.springframework.cloud]
08:01:47,930 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.cialty] to INFO
08:01:47,930 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@ff23ae7 - Propagating INFO level on Logger[com.cialty] onto the JUL framework
08:01:47,930 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.cialty] to false
08:01:47,930 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[com.cialty]
08:01:47,930 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [APPLICATION] to Logger[com.cialty]
08:01:47,930 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
08:01:47,930 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@ff23ae7 - Propagating INFO level on Logger[ROOT] onto the JUL framework
08:01:47,930 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[ROOT]
08:01:47,930 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [APPLICATION] to Logger[ROOT]
08:01:47,930 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
08:01:47,930 |-INFO in org.springframework.boot.logging.logback.SpringBootJoranConfigurator@423b2b62 - Registering current configuration as safe fallback point

Solution

  • Not sure if this is a bug in Spring-Boot or it's an expected behavior but the problem is in the way I was activating the profile

    spring:
     profiles:
        active: 
         - common-services  <------This will make spring generates 2 files as the default profile will be active as well.
    
    spring:
     profiles:
        active: common-services <------This will activate common-services only which results to generate 1 file only.