Spring Boot 版本: 2.3.4.RELEASE
不知道大家有没有过当线上出现问题的时候,需要某些DEBUG日志,但奈何当前使用时INFO。
如果想启用DEBUG就需要重新打包发版,但某些场景下重启有可能问题就不会复现了,真是脑阔疼啊。
今天我们就来说下Spring Boot 下的日志配置动态调整,让你的日志级别随心而动。
Spring Boot 系列:日志动态配置详解
在Spring Boot 内部使用的其实是Commons Logging, 而基于Spring Boot的配置加载机制为我们提供了Java Util Logging、Log4j2、Logback几种日志方式。
Logback是其默认的日志框架,如果没有特殊的必要真不建议更换了。(不要说性能了)
不要小瞧格式这种东西,在实际应用的时候是贼拉重要的一件事。
不知道大家的公司有没有统一的日志基础组件,当然没有也大概会有统一的日志配置文件吧。
想想如果你的日志格式不统一的话,如果每个项目都有自己的风格的话,你叫你的运维小伙伴怎么帮你切分日志?帮你报警呢?那真是正则写到死,完全靠爱发电了。(比如我们使用的Loghub 不统一要被运维打死的)
来看下我们的日志格式配置,这里只放PATTERN
-|%d{yyyy-MM-dd HH:mm:ss.SSS}|%-5level|%X{tid}|%thread|%logger{36}.%M:%L-%msg%n
先解释下各个位置:
这里不知道大家能否理解前面有一个 -|是为了什么? 其实是为了在正则切分的时候方便区分换行的日志,如异常堆栈的信息。
再说几个其他Spring Boot使用的小点,我们就来进入正题
下面我们就来说说在运行状态下的Spring Boot应用是怎么进行动态日志级别变更的
Actuator 想必了解过Spring Boot的都知道它的大名,监控、审计、度量信息等等。我们使用的优雅停机、健康检查、日志信息都是通过这玩意来实现的。
在我们使用了Actuator 后,我们就可以使用其Logger的REST接口来操作我们的日志了,有如下三个
1)、依赖必要的配置 Spring Boot Actuator (如果你继承了parent是不需要version的)
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-actuator</artifactId>
<version>2.3.4.RELEASE</version>
</dependency>
2)、配置文件
#注意,这里我只开启了loggers,health两个Actuator
management.endpoints.web.exposure.include=loggers,health
management.endpoint.loggers.enabled=true
3)、创建一个Controller
@RestController
@RequestMapping("/log")
public class TestLogController {
private Logger log = LoggerFactory.getLogger(TestLogController.class);
@GetMapping
public String log() {
log.trace("This is a TRACE level message");
log.debug("This is a DEBUG level message");
log.info("This is an INFO level message");
log.warn("This is a WARN level message");
log.error("This is an ERROR level message");
return "See the log for details";
}
}
4)、启动应用
此时在你启动应用后,如果你使用IDEA,就可以看到如下Mapping,有三个关于logger的REST接口
Spring Boot 系列:日志动态配置详解
5)、测试
此时,我先执行GET http://127.0.0.1:6080/log,控制台打印如下信息
2020-10-15 23:14:51.204 INFO 52628 --- [nio-6080-exec-7] c.q.chapter1.failure.TestLogController : This is an INFO level message
2020-10-15 23:14:51.220 WARN 52628 --- [nio-6080-exec-7] c.q.chapter1.failure.TestLogController : This is a WARN level message
2020-10-15 23:14:51.221 ERROR 52628 --- [nio-6080-exec-7] c.q.chapter1.failure.TestLogController : This is an ERROR level message
此时我们执行GET http://127.0.0.1:6080/actuator/loggers/ROOT返回{"configuredLevel":"INFO","effectiveLevel":"INFO"},代表此时我们应用的日志级别是INFO,ROOT表示的是根节点。
6)、修改级别
此时我们不想再看INFO信息,想将整个应用日志级别换位WARN的话,我们来执行POST http://127.0.0.1:6080/actuator/loggers/ROOT 参数为{"configuredLevel":"TRACE","effectiveLevel":"TRACE"}
此时我们再来执行GET http://127.0.0.1:6080/log,控制台打印如下信息
2020-10-15 23:24:11.481 TRACE 53552 --- [nio-6080-exec-3] c.q.chapter1.failure.TestLogController : This is a TRACE level message
2020-10-15 23:24:11.481 DEBUG 53552 --- [nio-6080-exec-3] c.q.chapter1.failure.TestLogController : This is a DEBUG level message
2020-10-15 23:24:11.481 INFO 53552 --- [nio-6080-exec-3] c.q.chapter1.failure.TestLogController : This is an INFO level message
2020-10-15 23:24:11.481 WARN 53552 --- [nio-6080-exec-3] c.q.chapter1.failure.TestLogController : This is a WARN level message
2020-10-15 23:24:11.481 ERROR 53552 --- [nio-6080-exec-3] c.q.chapter1.failure.TestLogController : This is an ERROR level message
另几种方法
这里我们主要使用的是Spring Boot Actuator Log ,所以我们也就来说说它的原理。
首先我们从依赖spring-boot-actuator中找到我们的LoggersEndpoint(所有的Actuator都是这一个路数),如图:
Spring Boot 系列:日志动态配置详解
熟悉Spring Boot加载机制的朋友都了解,在每个actuator Endpoint的背后,必然还会存在一个xxxEndpointAutoConfiguration 来为我们进行Endpoint 的加载。
而这些加载机制就都存放在spring-boot-actuator-autoconfigure中,我们在其中可以找到LoggersEndpointAutoConfiguration用于加载LoggersEndpoint的配置类。
来看下它的核心:
@Bean
@ConditionalOnBean(LoggingSystem.class)
@Conditional(OnEnabledLoggingSystemCondition.class)
@ConditionalOnMissingBean
public LoggersEndpoint loggersEndpoint(LoggingSystem loggingSystem,
ObjectProvider<LoggerGroups> springBootLoggerGroups) {
return new LoggersEndpoint(loggingSystem, springBootLoggerGroups.getIfAvailable(LoggerGroups::new));
}
可以看到两个重要的参数:
总结下:
1、我们依赖了spring-boot-starter-actuator包后,里面依赖了spring-boot-actuator-autoconfigure
2、在启动扫描到spring-boot-actuator-autoconfigure 下的META-INF/spring.factories时,LoggersEndpointAutoConfiguration会被加载到
3、LoggersEndpointAutoConfiguration 内又声明了LoggersEndpoin 并赋值LoggingSystem 和springBootLoggerGroups作为其参数
4、项目启动后我们通过LoggersEndpoint 接口进行日志数据访问
LoggingSystem的继承关系
通过上面可以了解到 LoggingSystem就是日志操作管理的核心了,所以我们先来看下他的Diagrams
Spring Boot 系列:日志动态配置详解
通过继承关系一眼可以看到,LogbackLoggingSystem就是我们的正主了,虽然说知道了正主那我们的LoggingSystem到底是怎么加载的呢?
LoggingSystem的加载
主要参与类说下:
不多说,先上图
Spring Boot 系列:日志动态配置详解
1、应用使用SpringApplication.run(Chapter1Application.class, args);启动
2、发送启动事件ApplicationStartingEvent、ApplicationEnvironmentPreparedEvent等
3、LoggingApplicationListener接收事件进行事件分发
4、LoggingApplicationListener接收事件ApplicationStartingEvent
5、LoggingApplicationListener调用内部onApplicationStartingEvent(ApplicationStartingEvent event)方法,使用LoggingSystem.get(classloader)初始化LoggingSystem。
6、然后调用LogbackLoggingSystem.beforeInitialize()(因为这里我们用的是logback)
7、LoggingApplicationListener接收事件ApplicationEnvironmentPreparedEvent
8、LoggingApplicationListener调用内部onApplicationEnvironmentPreparedEvent(ApplicationEnvironmentPreparedEvent event)方法
9、onApplicationEnvironmentPreparedEvent调用initialize(ConfigurableEnvironment environment, ClassLoader classLoader)方法,会根据环境变量配置进行logging system的初始化
最后,我们就来看看LoggersEndpoint就可以了,这里为了方便解读我就不全拷贝过来了,需要哪里选哪里
首先看我们对日志操作的三个接口:
这里拿一个public Map<String, Object> loggers()方法举例说明,其他的差不多
@ReadOperation
public LoggerLevels loggerLevels(@Selector String name) {
Assert.notNull(name, "Name must not be null");
LoggerGroup group = this.loggerGroups.get(name);
if (group != null) {
return new GroupLoggerLevels(group.getConfiguredLevel(), group.getMembers());
}
LoggerConfiguration configuration = this.loggingSystem.getLoggerConfiguration(name);
return (configuration != null) ? new SingleLoggerLevels(configuration) : null;
}
代码其实很简单,就不做过多解读了。
其实日志在我们的系统应用中很重要,对于问题的排查也是重要的凭证。根据经验我们系统的日志最好能做到几个点: