⭐⭐⭐ Spring Boot 项目实战 ⭐⭐⭐ Spring Cloud 项目实战
《Dubbo 实现原理与源码解析 —— 精品合集》 《Netty 实现原理与源码解析 —— 精品合集》
《Spring 实现原理与源码解析 —— 精品合集》 《MyBatis 实现原理与源码解析 —— 精品合集》
《Spring MVC 实现原理与源码解析 —— 精品合集》 《数据库实体设计合集》
《Spring Boot 实现原理与源码解析 —— 精品合集》 《Java 面试题 + Java 学习指南》

摘要: 原创出处 blog.csdn.net/qq_35387940/article/details/125062368 「小目标青年」欢迎转载,保留摘要,谢谢!


🙂🙂🙂关注**微信公众号:【芋道源码】**有福利:

  1. RocketMQ / MyCAT / Sharding-JDBC 所有源码分析文章列表
  2. RocketMQ / MyCAT / Sharding-JDBC 中文注释源码 GitHub 地址
  3. 您对于源码的疑问每条留言将得到认真回复。甚至不知道如何读源码也可以请教噢
  4. 新的源码解析文章实时收到通知。每周更新一篇左右
  5. 认真的源码交流微信群。

前言

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

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

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

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

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

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

什么效果? 先看一个实现后的效果图:

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

cat -n info.log |grep "a415ad50dbf84e99b1b56a31aacd209c"

或者

grep -10 'a415ad50dbf84e99b1b56a31aacd209c' info.log   (10是指上下10行)

不多说,开整。

正文

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

①pom.xml 依赖

<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-test</artifactId>
<scope>test</scope>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-logging</artifactId>
</dependency>
<!--lombok配置-->
<dependency>
<groupId>org.projectlombok</groupId>
<artifactId>lombok</artifactId>
<version>1.16.10</version>
</dependency>
</dependencies>

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

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false">
<!--日志存储路径-->
<property name="log" value="D:/test/log" />
<!-- 控制台输出 -->
<appender name="console" class="ch.qos.logback.core.ConsoleAppender">
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<!--输出格式化-->
<pattern>[%X{TRACE_ID}] %d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
</encoder>
</appender>
<!-- 按天生成日志文件 -->
<appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<!--日志文件名-->
<FileNamePattern>${log}/%d{yyyy-MM-dd}.log</FileNamePattern>
<!--保留天数-->
<MaxHistory>30</MaxHistory>
</rollingPolicy>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>[%X{TRACE_ID}] %d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
</encoder>
<!--日志文件最大的大小-->
<triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
<MaxFileSize>10MB</MaxFileSize>
</triggeringPolicy>
</appender>

<!-- 日志输出级别 -->
<root level="INFO">
<appender-ref ref="console" />
<appender-ref ref="file" />
</root>
</configuration>

application.yml

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

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

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

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

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.UUID;

/**
* @Author: JCccc
* @Date: 2022-5-30 10:45
* @Description:
*/
public class LogInterceptor implements HandlerInterceptor {

private static final String TRACE_ID = "TRACE_ID";

@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
String tid = UUID.randomUUID().toString().replace("-", "");
//可以考虑让客户端传入链路ID,但需保证一定的复杂度唯一性;如果没使用默认UUID自动生成
if (!StringUtils.isEmpty(request.getHeader("TRACE_ID"))){
tid=request.getHeader("TRACE_ID");
}
MDC.put(TRACE_ID, tid);
return true;
}

@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler,
@Nullable Exception ex) {
MDC.remove(TRACE_ID);
}

}

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

WebConfigurerAdapter.java 添加拦截器

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

/**
* @Author: JCccc
* @Date: 2022-5-30 10:47
* @Description:
*/
@Configuration
public class WebConfigurerAdapter implements WebMvcConfigurer {
@Bean
public LogInterceptor logInterceptor() {
return new LogInterceptor();
}

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

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

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

我们写个测试接口,看下效果:

@PostMapping("doTest")
public String doTest(@RequestParam("name") String name) throws InterruptedException {
log.info("入参 name={}",name);
testTrace();
log.info("调用结束 name={}",name);
return "Hello,"+name;
}
private void testTrace(){
log.info("这是一行info日志");
log.error("这是一行error日志");
testTrace2();
}
private void testTrace2(){
log.info("这也是一行info日志");

}

效果(OK的):

还没完。

接下来看一个场景, 使用子线程的场景:

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

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

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

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

import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.scheduling.annotation.EnableAsync;
import java.util.concurrent.Executor;

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

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

import org.slf4j.MDC;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;

import java.util.concurrent.Callable;
import java.util.concurrent.Future;

/**
* @Author: JCccc
* @Date: 2022-5-30 11:13
* @Description:
*/
public final class MyThreadPoolTaskExecutor extends ThreadPoolTaskExecutor {
public MyThreadPoolTaskExecutor() {
super();
}

@Override
public void execute(Runnable task) {
super.execute(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
}


@Override
public <T> Future<T> submit(Callable<T> task) {
return super.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
}

@Override
public Future<?> submit(Runnable task) {
return super.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
}
}

③ThreadMdcUtil.java

import org.slf4j.MDC;

import java.util.Map;
import java.util.UUID;
import java.util.concurrent.Callable;

/**
* @Author: JCccc
* @Date: 2022-5-30 11:14
* @Description:
*/
public final class ThreadMdcUtil {
private static final String TRACE_ID = "TRACE_ID";

// 获取唯一性标识
public static String generateTraceId() {
return UUID.randomUUID().toString();
}

public static void setTraceIdIfAbsent() {
if (MDC.get(TRACE_ID) == null) {
MDC.put(TRACE_ID, generateTraceId());
}
}

/**
* 用于父线程向线程池中提交任务时,将自身MDC中的数据复制给子线程
*
* @param callable
* @param context
* @param <T>
* @return
*/
public static <T> Callable<T> wrap(final Callable<T> callable, final Map<String, String> context) {
return () -> {
if (context == null) {
MDC.clear();
} else {
MDC.setContextMap(context);
}
setTraceIdIfAbsent();
try {
return callable.call();
} finally {
MDC.clear();
}
};
}

/**
* 用于父线程向线程池中提交任务时,将自身MDC中的数据复制给子线程
*
* @param runnable
* @param context
* @return
*/
public static Runnable wrap(final Runnable runnable, final Map<String, String> context) {
return () -> {
if (context == null) {
MDC.clear();
} else {
MDC.setContextMap(context);
}
setTraceIdIfAbsent();
try {
runnable.run();
} finally {
MDC.clear();
}
};
}
}

OK,重启服务,再看看效果:

可以看的,子线程的日志也被串起来了。

文章目录
  1. 1. 前言
  2. 2. 正文