乐趣区

关于java:记一次logback配置文件未生效问题排查

问题形容

最近在公司新建了一个 JAVA 微服务,采纳的是 springboot 框架,logback 作为日志模块的实现。在搭建的的过程中想起之前在文档中看到 springboot 反对用 logback-spring.xml 作为定制的 logback 配置文件。在这个文件中能够应用 spring 的定制化标签,比方能够依据以后失效的 profile 对日志文件进行配置,从而省去配置多份日志文件并在 profile 中指定具体以后失效的配置。在浏览了一下教程之后,我在 resources 目录下新建了 logback-spring.xml 的配置文件,内容如下:

<configuration scan="true" scanPeriod="100000" debug="false">

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

    <property name="LOG_BASE" value="logs/"/>

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${FILE_LOG_PATTERN}</pattern>
        </encoder>
    </appender>

    <!--  所有利用日志   -->
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_BASE}/application.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!-- rollover daily -->
            <fileNamePattern>${LOG_BASE}/application.log-%d{yyyy-MM-dd}.%i</fileNamePattern>
            <!-- each file should be at most 500MB, keep 60 days worth of history, but at most 20GB -->
            <maxFileSize>500MB</maxFileSize>
            <maxHistory>60</maxHistory>
            <totalSizeCap>20GB</totalSizeCap>
        </rollingPolicy>
        <encoder>
            <pattern>${FILE_LOG_PATTERN}</pattern>
        </encoder>
    </appender>
    <appender name="ASYNC-FILE" class="ch.qos.logback.classic.AsyncAppender">
        <!-- 不失落日志 -->
        <discardingThreshold >0</discardingThreshold>
        <!-- 更改默认的队列的深度, 该值会影响性能. 默认值为 256 -->
        <queueSize>512</queueSize>
        <!-- 增加附加的 appender, 最多只能增加一个 -->
        <appender-ref ref ="FILE"/>
    </appender>

    <!--  ERROR 日志  -->
    <appender name="ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_BASE}/application-error.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!-- rollover daily -->
            <fileNamePattern>${LOG_BASE}/application-error.log-%d{yyyy-MM-dd}.%i</fileNamePattern>
            <!-- each file should be at most 500MB, keep 60 days worth of history, but at most 20GB -->
            <maxFileSize>500MB</maxFileSize>
            <maxHistory>60</maxHistory>
            <totalSizeCap>20GB</totalSizeCap>
        </rollingPolicy>
        <encoder>
            <pattern>${FILE_LOG_PATTERN}</pattern>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
    </appender>
    <appender name="ASYNC-ERROR" class="ch.qos.logback.classic.AsyncAppender">
        <!-- 不失落日志 -->
        <discardingThreshold >0</discardingThreshold>
        <!-- 更改默认的队列的深度, 该值会影响性能. 默认值为 256 -->
        <queueSize>512</queueSize>
        <!-- 增加附加的 appender, 最多只能增加一个 -->
        <appender-ref ref ="ERROR"/>
    </appender>


    <springProfile name="local | boe">
        <root level="DEBUG">
            <appender-ref ref="CONSOLE"/>
            <appender-ref ref="ASYNC-FILE"/>
        </root>
    </springProfile>
    <springProfile name="!(local | boe)">
        <root level="INFO">
            <appender-ref ref="CONSOLE"/>
            <appender-ref ref="ASYNC-FILE"/>
            <appender-ref ref="ASYNC-ERROR"/>

        </root>
    </springProfile>
</configuration>

这个配置文件中重点关注 springProfile 这个标签,这个是 spring 定制的标签,依据以后失效的 profile 来决定应用哪一段配置,在这里当失效的 profile=local 或者 boe 时,会采纳下面这段配置,反之则采纳上面这段配置。实质上是冀望在测试环境时将日志的级别调整为 DEBUG,而到生产环境是则将级别调整为 INFO 并专门将 ERROR 日志输入到 ERROR 文件中便于排查。然而在测试时发现这个配置并没有失效,在测试环境也打印了 ERROR 文件、

排查过程

在询问谷歌无果后,通过在应用程序启动的时候打断点进行排查。springboot 通过 org.springframework.boot.logging.logback.LogbackLoggingSystem 这个类在利用启动的时候解析 logback 配置文件。这个类是 LoggingSystem 这个类的子类,而 LoggingSystem 类下还有其它的子类包含 JavaLoggingSystem,Log4j2LoggingSystem 等实现,从而实现反对不同日志模块。

在利用启动的时候,spring 会调用 org.springframework.boot.logging.AbstractLoggingSystem#initialize 办法对日志零碎进行初始化。如果在 profile 中指定了配置的地位(通过 logging.file),则会依照指定的目录寻找并加载配置,否则会扫描我的项目并依据不同日志零碎的默认配置门路寻找配置文件。

    public void initialize(LoggingInitializationContext initializationContext,
            String configLocation, LogFile logFile) {
        // 指定了配置文件目录
        if (StringUtils.hasLength(configLocation)) {initializeWithSpecificConfig(initializationContext, configLocation, logFile);
            return;
        }
        // 从默认门路中寻找配置文件
        initializeWithConventions(initializationContext, logFile);
    }

    private void initializeWithSpecificConfig(
            LoggingInitializationContext initializationContext, String configLocation,
            LogFile logFile) {
        // 依据目录加载日志文件
        configLocation = SystemPropertyUtils.resolvePlaceholders(configLocation);
        loadConfiguration(initializationContext, configLocation, logFile);
    }

在进入 initializeWithConventions 后,会先扫描不同日志零碎定义的默认配置门路并找到配置文件(getSelfInitializationConfig)。在 getSelfInitializationConfig 这个办法中调用了 getStandardConfigLocations 取得默认配置门路

    private void initializeWithConventions(LoggingInitializationContext initializationContext, LogFile logFile) {
        // 获取以后日志零碎的默认配置文件
        String config = getSelfInitializationConfig();
        if (config != null && logFile == null) {
            // self initialization has occurred, reinitialize in case of property changes
            reinitialize(initializationContext);
            return;
        }
        // 未在 classpath 下找到默认配置文件,则寻找 spring 定制的配置文件
        if (config == null) {config = getSpringInitializationConfig();
        }
        if (config != null) {loadConfiguration(initializationContext, config, logFile);
            return;
        }
        loadDefaults(initializationContext, logFile);
    }

    protected String getSelfInitializationConfig() {return findConfig(getStandardConfigLocations());
    }

getStandardConfigLocations 是一个形象办法,不同的日志零碎都进行了本人的实现。logback 提供的文件名称如下,能够看到并没有 logback-spring 文件。

    @Override
    protected String[] getStandardConfigLocations() {return new String[] { "logback-test.groovy", "logback-test.xml", "logback.groovy",
                "logback.xml" };
    }

而 findConfig 办法则在 classpath 下依照这些文件名称一一寻找,并返回找到的第一个配置文件。
当没有在 classpath 下找到默认配置文件,则寻找 spring 定制的配置文件,spring 配置文件实质上是在默认配置文件名称后加上 -spring 后缀并在 classpath 中进行检索、

    protected String[] getSpringConfigLocations() {String[] locations = getStandardConfigLocations();
        for (int i = 0; i < locations.length; i++) {String extension = StringUtils.getFilenameExtension(locations[i]);
            locations[i] = locations[i].substring(0,
                    locations[i].length() - extension.length() - 1) + "-spring."
                    + extension;
        }
        return locations;
    }

而当上述办法都没有找到配置的时候,就会加载日志零碎提供的默认配置。logback 的配置如下:

    @Override
    protected void loadDefaults(LoggingInitializationContext initializationContext,
            LogFile logFile) {LoggerContext context = getLoggerContext();
        stopAndReset(context);
        LogbackConfigurator configurator = new LogbackConfigurator(context);
        context.putProperty("LOG_LEVEL_PATTERN",
                initializationContext.getEnvironment().resolvePlaceholders("${logging.pattern.level:${LOG_LEVEL_PATTERN:%5p}}"));
        new DefaultLogbackConfiguration(initializationContext, logFile)
                .apply(configurator);
        context.setPackagingDataEnabled(true);
    }

那么为什么这里 springprofile 没有失效呢。打断点发现在 getSelfInitializationConfig 查找日志零碎默认配置文件时就找到了对应的 logback.xml 文件,从而不会再查找 spring 定制化配置文件(即默认配置文件的优先级高于 spring 配置文件)。而这个 logback 文件是依赖的别的包引入的 logback 配置,从而妨碍了 spring-boot 文件的加载 (这里也顺便说一下,提供给他人的二方包中正确的做法是不要引入日志的配置文件~)。具体从哪个依赖包中引入的能够从 springboot 的启动日志中看到:

这个问题的解决办法有两个:

  1. 将本人的 logback-spring 文件申明成 logback 或 logback.test.xml,它会笼罩别的包引入的 logback 配置,然而会导致局部 spring 标签生效
  2. 应用 logging.config 指定配置文件门路,这个配置能够是在 application.properties 文件中申明,也能够是在启动命令参数中用 -Dlogging.config 在启动时申明

总结

断点是一个好工具,多多应用,游刃有余。

退出移动版