问题描述 最近在公司新建了一个JAVA微服务,采用的是springboot框架,logback作为日志模块的实现。在搭建的的过程中想起之前在文档中看到springboot支持用logback-spring.xml作为定制的logback配置文件。在这个文件中可以使用spring的定制化标签,比如可以根据当前生效的profile对日志文件进行配置,从而省去配置多份日志文件并在profile中指定具体当前生效的配置。在阅读了一下教程之后,我在resources目录下新建了logback-spring.xml的配置文件,内容如下:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 <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" > <fileNamePattern > ${LOG_BASE}/application.log-%d{yyyy-MM-dd}.%i</fileNamePattern > <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 > <queueSize > 512</queueSize > <appender-ref ref ="FILE" /> </appender > <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" > <fileNamePattern > ${LOG_BASE}/application-error.log-%d{yyyy-MM-dd}.%i</fileNamePattern > <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 > <queueSize > 512</queueSize > <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),则会按照指定的目录寻找并加载配置,否则会扫描项目并根据不同日志系统的默认配置路径寻找配置文件。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 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获得默认配置路径
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 private void initializeWithConventions ( LoggingInitializationContext initializationContext, LogFile logFile) { String config = getSelfInitializationConfig(); if (config != null && logFile == null ) { reinitialize(initializationContext); return ; } 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文件。
1 2 3 4 5 @Override protected String[] getStandardConfigLocations() { return new String [] { "logback-test.groovy" , "logback-test.xml" , "logback.groovy" , "logback.xml" }; }
而findConfig方法则在classpath下按照这些文件名称逐个寻找,并返回找到的第一个配置文件。 当没有在classpath下找到默认配置文件,则寻找spring定制的配置文件,spring配置文件本质上是在默认配置文件名称后加上-spring后缀并在classpath中进行检索、
1 2 3 4 5 6 7 8 9 10 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的配置如下:
1 2 3 4 5 6 7 8 9 10 11 12 13 @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在启动时声明
总结 断点是一个好工具,多多使用,熟能生巧。
https://www.baeldung.com/spring-boot-logging