• 前言
• 正文

前言

從文章標題就知道，這篇文章是介紹些什么。

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

好像是的，確實這種現象是普遍存在的。

有時候一個業務調用鏈場景，很長，調了各種各樣的方法，看日志的時候，各個接口的日志穿插，確實讓人頭大。

模糊匹配搜索日志能解決嗎？ 能解決一點點。 但是不能完全呈現出整個鏈路相關的日志。

那要做到方便，很顯然，我們需要的是把同一次的業務調用鏈上的日志串起來。

什么效果？ 先看一個實現后的效果圖：

這樣下來，我們再配合模糊匹配查找日志，效果不就剛剛的了。

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();
}
};
}
}

OK，重啟服務，再看看效果：

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