SpringAOP+Logback+MDC实现全链路日志追踪

螺蛳小公鸡
1,878 阅读6分钟

一、背景

博主所在的公司因为有权限管理和架构规范，服务都部署到云上，只能通过日志系统查看日志。但是日志是通过kafka采集的，所有节点的日志都堆在一起，要想在像海一样的日志里面查询关键信息和调用链路比较困难。因此，实现全链路日志追踪显得非常重要。

二、方案调研

在Spring Boot中实现全链路日志跟踪，通常涉及到在请求处理的整个过程中（从前端到后端，再到可能的后端服务之间的调用）传递一个唯一的跟踪ID（如Trace ID）。这个ID可以用于在日志中标记和搜索特定请求的日志条目，从而实现全链路的日志跟踪。

以下是一些实现全链路日志跟踪的常用方法：

  1. 使用MDC（Mapped Diagnostic Context）

    MDC是log4j和logback等日志框架提供的一个功能，允许你在日志消息中嵌入上下文信息。你可以在请求开始时生成一个Trace ID，并将其放入MDC，然后在后续的日志记录中使用这个ID。

    示例（使用logback）：

    	MDC.put("traceId", traceId);  

	// 记录日志，此时log中会自动包含traceId  

	logger.info("Processing request...");  

	// ... 在请求处理过程中保持MDC中的traceId不变  

	// 请求处理完成后，可以选择性地清除MDC中的traceId  

	MDC.remove("traceId");

  2. 使用Spring Cloud的分布式追踪

    如果你的应用是微服务架构，并且已经在使用Spring Cloud，那么可以使用Spring Cloud Sleuth来实现分布式追踪。Sleuth会在HTTP请求头中自动注入Trace ID和Span ID，并在日志中输出这些信息。

    你需要在项目的依赖管理文件中添加Spring Cloud Sleuth的依赖，并在配置文件中启用相关功能。

  3. 自定义拦截器和过滤器

    你可以编写自定义的拦截器（用于Spring MVC）或过滤器（用于Servlet API），在请求进入和退出时生成和传递Trace ID。拦截器和过滤器可以访问请求和响应对象，因此可以在HTTP头中注入或提取Trace ID。

    示例（使用Spring MVC拦截器）：

    	@Component  

	public class TraceInterceptor implements HandlerInterceptor {  

	    @Override  

	    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {  

	        // 从请求头中提取或生成Trace ID  

	        // ...  

	        // 将Trace ID放入MDC或请求属性中  

	        return true;  

	    }  

	 

	    @Override  

	    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {  

	        // 清除MDC中的Trace ID（如果需要）  

	    }  

	}

  4. 使用OpenTracing或Zipkin等第三方追踪系统

    这些系统提供了更强大的分布式追踪功能，包括可视化的追踪数据、服务依赖图等。它们通常与Spring Cloud Sleuth集成良好，可以很容易地集成到你的Spring Boot应用中。

  5. 在日志格式中包含Trace ID

    无论你选择哪种方法生成和传递Trace ID，都应该在日志格式中包含这个ID。这样，在查看或搜索日志时，就可以很容易地找到与特定请求相关的所有日志条目。

  6. 跨服务传递Trace ID

    如果你的应用调用了其他后端服务，你需要在调用这些服务时传递Trace ID。这通常可以通过在HTTP请求头中添加自定义头来实现。在接收端，你可以从请求头中提取这个ID，并将其放入MDC或日志中。

三、方案选择

因为博主所做项目主要是SpringBoot框架，不涉及SpringCloud，考虑到适配性和集成难度，最后选择通过SpringAOP+Logback+MDC实现全链路日志追踪。

四、方案实施

4.1 添加依赖

以Maven为例，你可能需要添加以下依赖：

<!-- Spring AOP --> 
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-aop</artifactId> 
</dependency> 

<!-- Logback Classic --> 
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId> 
</dependency> 

<!-- Spring Boot Starter Logging (通常会包含Logback的依赖) --> 
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-logging</artifactId> 
</dependency>

4.2 配置Logback

在logback-spring.xml（或logback.xml）中配置Logback以包含MDC中的traceId。例如：

<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - [%X{traceId}] - %msg%n</pattern>
        </encoder>
    </appender> 
    
    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root> 
</configuration>

这里的%X{traceId}将会输出MDC中名为traceId的值。

4.3 创建AOP切面

创建一个Spring AOP切面来拦截方法调用，并在方法调用前后设置和清除MDC中的traceId。

@Aspect  
@Component  
public class TraceAspect {  
  
    @Pointcut("execution(* com.yourpackage..*.*(..))")  
    public void allMethods() {}  
  
    @Before("allMethods()")  
    public void beforeAdvice(JoinPoint joinPoint) {  
        // 生成traceId，这里只是简单示例，实际应用中可能需要更复杂的逻辑  
        String traceId = UUID.randomUUID().toString();  
        MDC.put("traceId", traceId);  
    }  
  
    @After("allMethods()")  
    public void afterAdvice() {  
        // 清除MDC中的traceId  
        MDC.clear();  
    }  
}

注意：上面的示例使用了@Before和@After注解来分别在方法调用前和调用后设置和清除MDC中的traceId。但是，在真实的应用场景中，你可能希望在HTTP请求的开始和结束时设置和清除traceId，这时你可能需要使用@Around注解，并在AOP切面中处理HTTP请求。

以我实际项目中代码为例，定义一个web全局拦截器，拦截HTTP请求中携带的traceId，如果没有携带就生成一个随机id，并在请求前后处理traceId。

import org.slf4j.MDC;
import org.springframework.stereotype.Component;

import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.Optional;
import java.util.UUID;

@Component
public class MDCFilter implements Filter {
    private static final String REQUEST_ID_HEADER = "requestId";
    private static final String REQUEST_ID = "requestId";

    @Override
    public void init(FilterConfig filterConfig) {
    }

    @Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
        HttpServletRequest request = (HttpServletRequest) servletRequest;
        HttpServletResponse response = (HttpServletResponse) servletResponse;
        String requestId = request.getHeader(REQUEST_ID_HEADER);
        String requestIdMDC = Optional.ofNullable(requestId).orElseGet(() -> UUID.randomUUID().toString());
        response.setHeader(REQUEST_ID_HEADER, requestIdMDC);
        MDC.put(REQUEST_ID, requestIdMDC);
        try {
            filterChain.doFilter(request,response);
        } finally {
            MDC.clear();
        }
    }

    @Override
    public void destroy() {
    }
}

4.4 多线程情况

上述处理没有考虑多线程的场景，而MDC（Mapped Diagnostic Context）是基于线程的，它为每个线程维护一个独立的映射。这意味着，如果在不同的线程中处理相同的请求，并且你希望这些线程共享相同的trace ID，你需要确保正确地将trace ID从一个线程传递到另一个线程。

解决方式：采用TaskDecorator的线程任务装饰器方式为线程池的线程提供traceId的传递操作。

4.4.1 定义任务装饰器

import lombok.NonNull;
import org.slf4j.MDC;
import org.springframework.core.task.TaskDecorator;
import org.springframework.util.ObjectUtils;

import java.util.Map;

public class MDCTaskDecorator implements TaskDecorator {
    @Override
    public @NonNull Runnable decorate(@NonNull Runnable runnable) {
        // 此时获取的是父线程的上下文数据
        Map<String, String> contextMap = MDC.getCopyOfContextMap();
        return () -> {
            try {
                if (!ObjectUtils.isEmpty(contextMap)) {
                    MDC.setContextMap(contextMap);
                }
                runnable.run();
            } finally {
                // 清除子线程的，避免内存溢出，就和ThreadLocal.remove()一个原因
                MDC.clear();
            }
        };
    }
}

4.4.2 定义线程池

@Configuration
public class PoolConfig {
    @Bean("taskExecutor")
    public Executor taskExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        //配置核心线程数
        executor.setCorePoolSize(5);
        //配置最大线程数
        executor.setMaxPoolSize(10);
        //配置队列大小
        executor.setQueueCapacity(100);
        //配置线程池中的线程的名称前缀
        executor.setThreadNamePrefix("mdc-trace-");
        // 异步MDC
        executor.setTaskDecorator(new MDCTaskDecorator());
        //执行初始化
        executor.initialize();
        return executor;
    }
}

4.4.3 使用线程池

@Resource
  @Qualifier("taskExecutor")
  private Executor executor;

  @PostMapping("/pool")
  public String pool() throws Exception{
      CompletableFuture<String> future = CompletableFuture.supplyAsync(() -> {
          log.info("线程池里面");
          try{
              Thread.sleep(1000);
          } catch (Exception ignored){}

          return "";
      }, executor);
      future.thenApplyAsync( value ->{
          log.info("线程池组合操作");
          try{
              Thread.sleep(1000);
          } catch (Exception ignored) {}
          return value + "1";
      }, executor);
      return future.get();
  }

或者异步调用时使用@Async("taskExecutor")。

成果展示

图片.png

总结

通过SrpingAOP+Logback+MDC可以实现简单的全链路日志追踪，并且考虑了多线程的情形，可以为我们排查问题提供很大的帮助，特别是业务逻辑链路较长，日志量较大时，能快速定位问题，并提高系统的监控和统计能力。

参考：【developer.aliyun.com/article/149…

avatar
文章
阅读
粉丝