记一次logback配置文件未生效问题排查记一次logback配置文件未生效问

问题描述最近在公司新建了一个JAVA微服务，采用的是springboot框架，logback作为日志模块的实现。在搭建的的过程中想起之前在文档中看到springboot支持用logback-spring.xml作为定制的logback配置文件。在这个文件中可以使用spring的定制化标签，比如可以根据当前生效的profile对日志文件进行配置，从而省去配置多份日志文件并在profile中指定具体当前生效的配置。在阅读了一下教程之后，我在resources目录下新建了logback-spring.xml的配置文件，内容如下：

${FILE_LOG_PATTERN} ${LOG_BASE}/application.log ${LOG_BASE}/application.log-%d{yyyy-MM-dd}.%i500MB 60 20GB ${FILE_LOG_PATTERN} 0512${LOG_BASE}/application-error.log ${LOG_BASE}/application-error.log-%d{yyyy-MM-dd}.%i500MB 60 20GB ${FILE_LOG_PATTERN} ERROR 0512

这个配置文件中重点关注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()); }

【记一次logback配置文件未生效问题排查】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的启动日志中看到：

文章图片

这个问题的解决方法有两个：

将自己的logback-spring文件声明成logback或logback.test.xml，它会覆盖别的包引入的logback配置，但是会导致部分spring标签失效
使用logging.config指定配置文件路径，这个配置可以是在application.properties文件中声明，也可以是在启动命令参数中用-Dlogging.config在启动时声明

总结断点是一个好工具，多多使用，熟能生巧。