手动实现SpringBoot日志链路追踪-电子发烧友网

前言
正文

前言

从文章标题就知道，这篇文章是介绍些什么。

这是我一位朋友的问题反馈：

好像是的，确实这种现象是普遍存在的。

有时候一个业务调用链场景，很长，调了各种各样的方法，看日志的时候，各个接口的日志穿插，确实让人头大。

模糊匹配搜索日志能解决吗？能解决一点点。但是不能完全呈现出整个链路相关的日志。

那要做到方便，很显然，我们需要的是把同一次的业务调用链上的日志串起来。

什么效果？先看一个实现后的效果图：

这样下来，我们再配合模糊匹配查找日志，效果不就刚刚的了。

cat-ninfo.log|grep"a415ad50dbf84e99b1b56a31aacd209c"

或者

grep-10'a415ad50dbf84e99b1b56a31aacd209c'info.log（10是指上下10行）

不多说，开整。

基于 Spring Boot + MyBatis Plus + Vue & Element 实现的后台管理系统 + 用户小程序，支持 RBAC 动态权限、多租户、数据权限、工作流、三方登录、支付、短信、商城等功能

项目地址：https://github.com/YunaiV/ruoyi-vue-pro

视频教程：https://doc.iocoder.cn/video/

正文

惯例，先看一眼这次实战最终工程的结构：

①pom.xml 依赖

<dependencies>
<dependency>
<groupId>org.springframework.bootgroupId>
<artifactId>spring-boot-starter-webartifactId>
dependency>
<dependency>
<groupId>org.springframework.bootgroupId>
<artifactId>spring-boot-starter-testartifactId>
<scope>testscope>
dependency>
<dependency>
<groupId>org.springframework.bootgroupId>
<artifactId>spring-boot-starter-loggingartifactId>
dependency>

<dependency>
<groupId>org.projectlombokgroupId>
<artifactId>lombokartifactId>
<version>1.16.10version>
dependency>
dependencies>

②整合logback，打印日志，logback-spring.xml (简单配置下)


<configurationdebug="false">

<propertyname="log"value="D:/test/log"/>

<appendername="console"class="ch.qos.logback.core.ConsoleAppender">
<encoderclass="ch.qos.logback.classic.encoder.PatternLayoutEncoder">

<pattern>[%X{TRACE_ID}]%d{yyyy-MM-ddHHss.SSS}[%thread]%-5level%logger{50}-%msg%npattern>
encoder>
appender>

<appendername="file"class="ch.qos.logback.core.rolling.RollingFileAppender">
<rollingPolicyclass="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

<FileNamePattern>${log}/%d{yyyy-MM-dd}.logFileNamePattern>

<MaxHistory>30MaxHistory>
rollingPolicy>
<encoderclass="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>[%X{TRACE_ID}]%d{yyyy-MM-ddHHss.SSS}[%thread]%-5level%logger{50}-%msg%npattern>
encoder>

<triggeringPolicyclass="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
<MaxFileSize>10MBMaxFileSize>
triggeringPolicy>
appender>


<rootlevel="INFO">
<appender-refref="console"/>
<appender-refref="file"/>
root>
configuration>

application.yml

server:
port:8826
logging:
config:classpath:logback-spring.xml

③自定义日志拦截器 LogInterceptor.java

用途：每一次链路，线程维度，添加最终的链路ID TRACE_ID。

importorg.slf4j.MDC;
importorg.springframework.lang.Nullable;
importorg.springframework.util.StringUtils;
importorg.springframework.web.servlet.HandlerInterceptor;

importjavax.servlet.http.HttpServletRequest;
importjavax.servlet.http.HttpServletResponse;
importjava.util.UUID;

/**
*@Author:JCccc
*@Date:2022-5-3010:45
*@Description:
*/
publicclassLogInterceptorimplementsHandlerInterceptor{

privatestaticfinalStringTRACE_ID="TRACE_ID";

@Override
publicbooleanpreHandle(HttpServletRequestrequest,HttpServletResponseresponse,Objecthandler){
Stringtid=UUID.randomUUID().toString().replace("-","");
//可以考虑让客户端传入链路ID，但需保证一定的复杂度唯一性；如果没使用默认UUID自动生成
if(!StringUtils.isEmpty(request.getHeader("TRACE_ID"))){
tid=request.getHeader("TRACE_ID");
}
MDC.put(TRACE_ID,tid);
returntrue;
}

@Override
publicvoidafterCompletion(HttpServletRequestrequest,HttpServletResponseresponse,Objecthandler,
@NullableExceptionex){
MDC.remove(TRACE_ID);
}

}

MDC(Mapped Diagnostic Context)诊断上下文映射，是@Slf4j提供的一个支持动态打印日志信息的工具。

WebConfigurerAdapter.java 添加拦截器

importorg.springframework.context.annotation.Bean;
importorg.springframework.context.annotation.Configuration;
importorg.springframework.web.servlet.config.annotation.InterceptorRegistry;
importorg.springframework.web.servlet.config.annotation.WebMvcConfigurer;

/**
*@Author:JCccc
*@Date:2022-5-3010:47
*@Description:
*/
@Configuration
publicclassWebConfigurerAdapterimplementsWebMvcConfigurer{
@Bean
publicLogInterceptorlogInterceptor(){
returnnewLogInterceptor();
}

@Override
publicvoidaddInterceptors(InterceptorRegistryregistry){
registry.addInterceptor(logInterceptor());
//可以具体制定哪些需要拦截，哪些不拦截，其实也可以使用自定义注解更灵活完成
//.addPathPatterns("/**")
//.excludePathPatterns("/testxx.html");
}
}

ps: 其实这个拦截的部分改为使用自定义注解+aop也是很灵活的。

到这时候，其实已经完成，就是这么简单。

我们写个测试接口，看下效果：

@PostMapping("doTest")
publicStringdoTest(@RequestParam("name")Stringname)throwsInterruptedException{
log.info("入参name={}",name);
testTrace();
log.info("调用结束name={}",name);
return"Hello,"+name;
}
privatevoidtestTrace(){
log.info("这是一行info日志");
log.error("这是一行error日志");
testTrace2();
}
privatevoidtestTrace2(){
log.info("这也是一行info日志");

}

效果（OK的）：

还没完。

接下来看一个场景，使用子线程的场景：

故意写一个异步线程，加入这个调用里面：

再次执行看开效果，显然子线程丢失了trackId：

所以我们需要针对子线程使用情形，做调整，思路：将父线程的trackId传递下去给子线程即可。

①ThreadPoolConfig.java 定义线程池，交给spring管理

importorg.springframework.context.annotation.Bean;
importorg.springframework.context.annotation.Configuration;
importorg.springframework.scheduling.annotation.EnableAsync;
importjava.util.concurrent.Executor;

/**
*@Author:JCccc
*@Date:2022-5-3011:07
*@Description:
*/
@Configuration
@EnableAsync
publicclassThreadPoolConfig{
/**
*声明一个线程池
*
*@return执行器
*/
@Bean("MyExecutor")
publicExecutorasyncExecutor(){
MyThreadPoolTaskExecutorexecutor=newMyThreadPoolTaskExecutor();
//核心线程数5：线程池创建时候初始化的线程数
executor.setCorePoolSize(5);
//最大线程数5：线程池最大的线程数，只有在缓冲队列满了之后才会申请超过核心线程数的线程
executor.setMaxPoolSize(5);
//缓冲队列500：用来缓冲执行任务的队列
executor.setQueueCapacity(500);
//允许线程的空闲时间60秒：当超过了核心线程出之外的线程在空闲时间到达之后会被销毁
executor.setKeepAliveSeconds(60);
//线程池名的前缀：设置好了之后可以方便我们定位处理任务所在的线程池
executor.setThreadNamePrefix("asyncJCccc");
executor.initialize();
returnexecutor;
}
}

② MyThreadPoolTaskExecutor.java 是我们自己写的，重写了一些方法：

importorg.slf4j.MDC;
importorg.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;

importjava.util.concurrent.Callable;
importjava.util.concurrent.Future;

/**
*@Author:JCccc
*@Date:2022-5-3011:13
*@Description:
*/
publicfinalclassMyThreadPoolTaskExecutorextendsThreadPoolTaskExecutor{
publicMyThreadPoolTaskExecutor(){
super();
}

@Override
publicvoidexecute(Runnabletask){
super.execute(ThreadMdcUtil.wrap(task,MDC.getCopyOfContextMap()));
}


@Override
publicFuturesubmit(Callabletask){
returnsuper.submit(ThreadMdcUtil.wrap(task,MDC.getCopyOfContextMap()));
}

@Override
publicFuturesubmit(Runnabletask){
returnsuper.submit(ThreadMdcUtil.wrap(task,MDC.getCopyOfContextMap()));
}
}

③ThreadMdcUtil.java

importorg.slf4j.MDC;

importjava.util.Map;
importjava.util.UUID;
importjava.util.concurrent.Callable;

/**
*@Author:JCccc
*@Date:2022-5-3011:14
*@Description:
*/
publicfinalclassThreadMdcUtil{
privatestaticfinalStringTRACE_ID="TRACE_ID";

//获取唯一性标识
publicstaticStringgenerateTraceId(){
returnUUID.randomUUID().toString();
}

publicstaticvoidsetTraceIdIfAbsent(){
if(MDC.get(TRACE_ID)==null){
MDC.put(TRACE_ID,generateTraceId());
}
}

/**
*用于父线程向线程池中提交任务时，将自身MDC中的数据复制给子线程
*
*@paramcallable
*@paramcontext
*@param
*@return
*/
publicstaticCallablewrap(finalCallablecallable,finalMapcontext){
return()->{
if(context==null){
MDC.clear();
}else{
MDC.setContextMap(context);
}
setTraceIdIfAbsent();
try{
returncallable.call();
}finally{
MDC.clear();
}
};
}

/**
*用于父线程向线程池中提交任务时，将自身MDC中的数据复制给子线程
*
*@paramrunnable
*@paramcontext
*@return
*/
publicstaticRunnablewrap(finalRunnablerunnable,finalMapcontext){
return()->{
if(context==null){
MDC.clear();
}else{
MDC.setContextMap(context);
}
setTraceIdIfAbsent();
try{
runnable.run();
}finally{
MDC.clear();
}
};
}
}