基于SpringBoot实现,让日志像诗一样有韵律
前言
在传统系统中,如果能够提供日志输出,基本上已经能够满足需求的。但一旦将系统拆分成两套及以上的系统,再加上负载均衡等,调用链路就变得复杂起来。
特别是进一步向微服务方向演化,如果没有日志的合理规划、链路追踪,那么排查日志将变得异常困难。
比如系统A、B、C,调用链路为A -> B -> C,如果每套服务都是双活,则调用路径有2的三次方种可能性。如果系统更多,服务更多,调用链路则会成指数增长。
因此,无论是几个简单的内部服务调用,还是复杂的微服务系统,都需要通过一个机制来实现日志的链路追踪。让你系统的日志输出,像诗一样有形式美,又有和谐的韵律。
日志追踪其实已经有很多现成的框架了,比如Sleuth、Zipkin等组件。但这不是我们要讲的重点,本文重点基于Spring Boot、LogBack来手写实现一个简单的日志调用链路追踪功能。基于此实现模式,大家可以更细粒度地去实现。
Spring Boot中集成Logback
Spring Boot本身就内置了日志功能,这里使用logback日志框架,并对输出结果进行格式化。先来看一下SpringBoot对Logback的内置集成,依赖关系如下。当项目中引入了:
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
spring-boot-starter-web中间接引入了:
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter</artifactId>
</dependency>
spring-boot-starter又引入了logging的starter:
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-logging</artifactId>
</dependency>
在logging中真正引入了所需的logback包:
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-to-slf4j</artifactId>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>jul-to-slf4j</artifactId>
</dependency>
因此,我们使用时,只需将logback-spring.xml配置文件放在resources目录下即可。理论上配置文件命名为logback.xml也是支持的,但Spring Boot官网推荐使用的名称为:logback-spring.xml。
然后,在logback-spring.xml中进行日志输出的配置即可。这里不贴全部代码了,只贴出来相关日志输出格式部分,以控制台输出为例:
<property name="CONSOLE_LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} %contextName [%thread] %-5level [%X{requestId}] %logger{36} - %msg%n"/>
在value属性的表达式中,我们新增了自定义的变量值requestId,通过“[%X{requestId}]”的形式来展示。
这个requestId便是我们用来追踪日志的唯一标识。如果一个请求,从头到尾都使用了同一个requestId便可以把整个请求链路串联起来。如果系统还基于EKL等日志搜集工具进行统一收集,就可以更方便地查看整个日志的调用链路了。
那么,这个requestId变量是如何来的,又存储在何处呢?要了解这个,我们要先来了解一下日志框架提供的MDC功能。
什么是MDC?
MDC(Mapped Diagnostic Contexts) 是一个线程安全的存放诊断日志的容器。MDC是slf4j提供的适配其他具体日志实现包的工具类,目前只有logback和log4j支持此功能。
MDC是线程独立、线程安全的,通常无论是HTTP还是RPC请求,都是在各自独立的线程中完成的,这与MDC的机制可以很好地契合。
在使用MDC功能时,我们主要使用是put方法,该方法间接的调用了MDCAdapter接口的put方法。
看一下接口MDCAdapter其中一个实现类BasicMDCAdapter中的代码来:
public class BasicMDCAdapter implements MDCAdapter {
private InheritableThreadLocal<Map<String, String>> inheritableThreadLocal = new InheritableThreadLocal<Map<String, String>>() {
@Override
protected Map<String, String> childValue(Map<String, String> parentValue) {
if (parentValue == null) {
return null;
}
return new HashMap<String, String>(parentValue);
}
};
public void put(String key, String val) {
if (key == null) {
throw new IllegalArgumentException("key cannot be null");
}
Map<String, String> map = inheritableThreadLocal.get();
if (map == null) {
map = new HashMap<String, String>();
inheritableThreadLocal.set(map);
}
map.put(key, val);
}
// ...
}
通过源码可以看出内部持有一个InheritableThreadLocal的实例,该实例中通过HashMap来保存context数据。
此外,MDC提供了put/get/clear等几个核心接口,用于操作ThreadLocal中存储的数据。而在logback.xml中,可在layout中通过声明“%X{requestId}”这种形式来获得MDC中存储的数据,并进行打印此信息。
基于MDC的这些特性,因此它经常被用来做日志链路跟踪、动态配置用户自定义信息(比如requestId、sessionId等)等场景。
实战使用
上面了解了一些基础的原理知识,下面我们就来看看如何基于日志框架的MDC功能实现日志的追踪。
工具类准备
首先定义一些工具类,这个强烈建议大家将一些操作通过工具类的形式进行实现,这是写出优雅代码的一部分,也避免后期修改时每个地方都需要改。
TraceID(我们定义参数名为requestId)的生成类,这里采用UUID进行生成,当然可根据你的场景和需要,通过其他方式进行生成。
public class TraceIdUtils {
/**
* 生成traceId
*
* @return TraceId 基于UUID
*/
public static String getTraceId() {
return UUID.randomUUID().toString().replace("-", "");
}
}
对Context内容的操作工具类TraceIdContext:
public class TraceIdContext {
public static final String TRACE_ID_KEY = "requestId";
public static void setTraceId(String traceId) {
if (StringLocalUtil.isNotEmpty(traceId)) {
MDC.put(TRACE_ID_KEY, traceId);
}
}
public static String getTraceId() {
String traceId = MDC.get(TRACE_ID_KEY);
return traceId == null ? "" : traceId;
}
public static void removeTraceId() {
MDC.remove(TRACE_ID_KEY);
}
public static void clearTraceId() {
MDC.clear();
}
}
通过工具类,方便所有服务统一使用,比如requestId可以统一定义,避免每处都不一样。这里不仅提供了set方法,还提供了移除和清理的方法。
需要注意的是,MDC.clear()方法的使用。如果所有的线程都是通过new Thread方法建立的,线程消亡之后,存储的数据也随之消亡,这倒没什么。但如果采用的是线程池的情况时,线程是可以被重复利用的,如果之前线程的MDC内容没有清除掉,再次从线程池中获取这个线程,会取出之前的数据(脏数据),会导致一些不可预期的错误,所以当前线程结束后一定要清掉。
Filter拦截
既然我们要实现日志链路的追踪,最直观的思路就是在访问的源头生成一个请求ID,然后一路传下去,直到这个请求完成。这里以Http为例,通过Filter来拦截请求,并将数据通过Http的Header来存储和传递数据。涉及到系统之间调用时,调用方设置requestId到Header中,被调用方从Header中取即可。
Filter的定义:
public class TraceIdRequestLoggingFilter extends AbstractRequestLoggingFilter {
@Override
protected void beforeRequest(HttpServletRequest request, String message) {
String requestId = request.getHeader(TraceIdContext.TRACE_ID_KEY);
if (StringLocalUtil.isNotEmpty(requestId)) {
TraceIdContext.setTraceId(requestId);
} else {
TraceIdContext.setTraceId(TraceIdUtils.getTraceId());
}
}
@Override
protected void afterRequest(HttpServletRequest request, String message) {
TraceIdContext.removeTraceId();
}
}
在beforeRequest方法中,从Header中获取requestId,如果获取不到则视为“源头”,生成一个requestId,设置到MDC当中。当这个请求完成时,将设置的requestId移除,防止上面说到的线程池问题。系统中每个服务都可以通过上述方式实现,整个请求链路就串起来了。
当然,上面定义的Filter是需要进行初始化的,在Spring Boot中实例化方法如下:
@Configuration
public class TraceIdConfig {
@Bean
public TraceIdRequestLoggingFilter traceIdRequestLoggingFilter() {
return new TraceIdRequestLoggingFilter();
}
}
针对普通的系统调用,上述方式基本上已经能满足了,实践中可根据自己的需要在此基础上进行扩展。这里使用的是Filter,也可以通过拦截器、Spring的AOP等方式进行实现。
微服务中的Feign
如果你的系统是基于Spring Cloud中的Feign组件进行调用,则可通过实现RequestInterceptor拦截器来达到添加requestId效果。具体实现如下:
@Configuration
public class FeignConfig implements RequestInterceptor {
@Override
public void apply(RequestTemplate requestTemplate) {
requestTemplate.header(TraceIdContext.TRACE_ID_KEY, TraceIdContext.getTraceId());
}
}
结果验证
当完成上述操作之后,对一个Controller进行请求,会打印如下的日志:
2021-04-13 10:58:31.092 cloud-sevice-consumer-demo [http-nio-7199-exec-1] INFO [ef76526ca96242bc8e646cdef3ab31e6] c.b.demo.controller.CityController - getCity
2021-04-13 10:58:31.185 cloud-sevice-consumer-demo [http-nio-7199-exec-1] WARN [ef76526ca96242bc8e646cdef3ab31e6] o.s.c.o.l.FeignBlockingLoadBalancerClient -
可以看到requestID已经被成功添加。当我们排查日志时,只需找到请求的关键信息,然后根据关键信息日志中的requestId值就可以把整个日志串联起来。
小结
最后,我们来回顾一下日志追踪的整个过程:当请求到达第一个服务器,服务检查requestId是否存在,如果不存在,则创建一个,放入MDC当中;服务调用其他服务时,再通过Header将requestId进行传递;而每个服务的logback配置requestId的输出。从而达到从头到尾将日志串联的效果。
在学习本文,如果你只学到了日志追踪,那是一种损失,因为文中还涉及到了SpringBoot对logback的集成、MDC的底层实现及坑、过滤器的使用、Feign的请求拦截器等。如果感兴趣,每个都可以发散一下,学习到更多的知识点。
原文链接:http://mp.weixin.qq.com/s?__biz=MzI0NDAzMzIyNQ==&mid=2654070846&idx=1&sn=8bb1843d238e9c9830b6baf734dbc343&utm_source=tuicool&utm_medium=referral
如果觉得本文对你有帮助,可以关注一下我公众号,回复关键字【面试】即可得到一份Java核心知识点整理与一份面试大礼包!另有更多技术干货文章以及相关资料共享,大家一起学习进步!
- 真香!Github超牛X的SpringBoot vue项目开发文档 源码限时开源!
- Github又爆神作,阿里JVM垃圾回收全解小册全网开源!(算法 底层实现)
- 应“云”而生的 Java 框架:构建本机可执行文件
- 直击灵魂!阿里技术官甩出内部爆款性能优化实战笔记,理论实战一键搞定!
- 来了来了!阿里内部面试参考指南(泰山版)限时开源分享,差距不止一点点!
- 香!阿里内部全套Java面试资源限时开源!差距不止一点点
- 金三银四期间获千万下载量!阿里大牛熬夜45天整理出来的Java面试突击手册也太香了!
- 阿里高工熬夜18天码出Java150K字面试宝典,却遭Github全面封杀
- 完美面试宝典?终于有阿里大牛将1000道大厂Java面试真题收录成册,全网开源了!
- 基于SpringBoot实现,让日志像诗一样有韵律
- 一战到底!终于有阿里大牛把对标阿里P7的Java学习路线与架构进阶宝典整理成册全网开源了!
- 基础到源码一键搞定:阿里大牛手码651K字的JDK源码速成笔记太强了!
- 他来了他来了!知乎上线2小时遭疯狂转载的阿里Java核心框架指导手册(2021全彩版)太香了!
- 泪目!刷完这份阿里面试突击手册我再也不是那个Java面试十面九败最后只能去小公司的弟弟了!
- 牛掰,阿里金三银四Java涨薪秘籍全网开源,却连夜遭Github、知乎等平台连夜下架!
- 65w字!阿里分布式开发小册Github新开源!原理实践双飞
- 干货来袭!阿里技术官甩出2021最新SpringCloudAlibaba全解,理论实战齐飞!
- 好家伙!Github又现神作,阿里大牛亲码24W字面试总结也太香了!(涵盖P5到P8所有技术点)
- Github限时开放!阿里内部强推微服务容器化参考指南我粉了
- 重磅!不容错过的阿里内部Spring Cloud Alibaba速成手册也太赞了(2021版)