Spring Boot如何實(shí)現(xiàn)日志鏈路追蹤

前言

正文

前言

從文章標(biāo)題就知道，這篇文章是介紹些什么。

這是我一位朋友的問題反饋：

好像是的，確實(shí)這種現(xiàn)象是普遍存在的。

有時(shí)候一個(gè)業(yè)務(wù)調(diào)用鏈場(chǎng)景，很長(zhǎng)，調(diào)了各種各樣的方法，看日志的時(shí)候，各個(gè)接口的日志穿插，確實(shí)讓人頭大。

模糊匹配搜索日志能解決嗎？ 能解決一點(diǎn)點(diǎn)。 但是不能完全呈現(xiàn)出整個(gè)鏈路相關(guān)的日志。

那要做到方便，很顯然，我們需要的是把同一次的業(yè)務(wù)調(diào)用鏈上的日志串起來。

什么效果？ 先看一個(gè)實(shí)現(xiàn)后的效果圖：

這樣下來，我們?cè)倥浜夏：ヅ洳檎胰罩?，效果不就剛剛的了?/p>

cat-ninfo.log|grep"a415ad50dbf84e99b1b56a31aacd209c"

或者

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

不多說，開整。

基于 Spring Boot + MyBatis Plus + Vue & Element 實(shí)現(xiàn)的后臺(tái)管理系統(tǒng) + 用戶小程序，支持 RBAC 動(dòng)態(tài)權(quán)限、多租戶、數(shù)據(jù)權(quán)限、工作流、三方登錄、支付、短信、商城等功能

項(xiàng)目地址：https://github.com/YunaiV/ruoyi-vue-pro

視頻教程：https://doc.iocoder.cn/video/

正文

慣例，先看一眼這次實(shí)戰(zhàn)最終工程的結(jié)構(gòu)：

①pom.xml 依賴

org.springframework.boot
spring-boot-starter-web


org.springframework.boot
spring-boot-starter-test
test


org.springframework.boot
spring-boot-starter-logging

 

org.projectlombok
lombok
1.16.10

②整合logback，打印日志，logback-spring.xml (簡(jiǎn)單配置下)

 

 


 
[%X{TRACE_ID}]%d{yyyy-MM-ddHHss.SSS}[%thread]%-5level%logger{50}-%msg%n


 


 
${log}/%d{yyyy-MM-dd}.log
 
30


[%X{TRACE_ID}]%d{yyyy-MM-ddHHss.SSS}[%thread]%-5level%logger{50}-%msg%n

 

10MB



 

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，但需保證一定的復(fù)雜度唯一性；如果沒使用默認(rèn)UUID自動(dòng)生成
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提供的一個(gè)支持動(dòng)態(tài)打印日志信息的工具。

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());
//可以具體制定哪些需要攔截，哪些不攔截，其實(shí)也可以使用自定義注解更靈活完成
//.addPathPatterns("/**")
//.excludePathPatterns("/testxx.html");
}
}

ps: 其實(shí)這個(gè)攔截的部分改為使用自定義注解+aop也是很靈活的。

到這時(shí)候，其實(shí)已經(jīng)完成，就是這么簡(jiǎn)單。

我們寫個(gè)測(cè)試接口，看下效果：

@PostMapping("doTest")
publicStringdoTest(@RequestParam("name")Stringname)throwsInterruptedException{
log.info("入?yún)ame={}",name);
testTrace();
log.info("調(diào)用結(jié)束name={}",name);
return"Hello,"+name;
}
privatevoidtestTrace(){
log.info("這是一行info日志");
log.error("這是一行error日志");
testTrace2();
}
privatevoidtestTrace2(){
log.info("這也是一行info日志");

}

效果（OK的）：

還沒完。

接下來看一個(gè)場(chǎng)景， 使用子線程的場(chǎng)景：

故意寫一個(gè)異步線程，加入這個(gè)調(diào)用里面：

再次執(zhí)行看開效果，顯然子線程丟失了trackId：

所以我們需要針對(duì)子線程使用情形，做調(diào)整，思路： 將父線程的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{
/**
*聲明一個(gè)線程池
*
*@return執(zhí)行器
*/
@Bean("MyExecutor")
publicExecutorasyncExecutor(){
MyThreadPoolTaskExecutorexecutor=newMyThreadPoolTaskExecutor();
//核心線程數(shù)5：線程池創(chuàng)建時(shí)候初始化的線程數(shù)
executor.setCorePoolSize(5);
//最大線程數(shù)5：線程池最大的線程數(shù)，只有在緩沖隊(duì)列滿了之后才會(huì)申請(qǐng)超過核心線程數(shù)的線程
executor.setMaxPoolSize(5);
//緩沖隊(duì)列500：用來緩沖執(zhí)行任務(wù)的隊(duì)列
executor.setQueueCapacity(500);
//允許線程的空閑時(shí)間60秒：當(dāng)超過了核心線程出之外的線程在空閑時(shí)間到達(dá)之后會(huì)被銷毀
executor.setKeepAliveSeconds(60);
//線程池名的前綴：設(shè)置好了之后可以方便我們定位處理任務(wù)所在的線程池
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";

//獲取唯一性標(biāo)識(shí)
publicstaticStringgenerateTraceId(){
returnUUID.randomUUID().toString();
}

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

/**
*用于父線程向線程池中提交任務(wù)時(shí)，將自身MDC中的數(shù)據(jù)復(fù)制給子線程
*
*@paramcallable
*@paramcontext
*@param
*@return
*/
publicstaticCallablewrap(finalCallablecallable,finalMapcontext){
return()->{
if(context==null){
MDC.clear();
}else{
MDC.setContextMap(context);
}
setTraceIdIfAbsent();
try{
returncallable.call();
}finally{
MDC.clear();
}
};
}

/**
*用于父線程向線程池中提交任務(wù)時(shí)，將自身MDC中的數(shù)據(jù)復(fù)制給子線程
*
*@paramrunnable
*@paramcontext
*@return
*/
publicstaticRunnablewrap(finalRunnablerunnable,finalMapcontext){
return()->{
if(context==null){
MDC.clear();
}else{
MDC.setContextMap(context);
}
setTraceIdIfAbsent();
try{
runnable.run();
}finally{
MDC.clear();
}
};
}
}

OK，重啟服務(wù)，再看看效果：

可以看的，子線程的日志也被串起來了。