SpringBoot 代码实现日志打印 traceId

背景：在分布式服务架构下，一个 Web 请求从网关流入，有可能会调用多个服务对请求进行处理，拿到最终结果。在这个过程中每个服务之间的通信又是单独的网络请求，无论请求流经的哪个服务除了故障或者处理过慢都会对前端造成影响。...

ACGkaka_

4995人浏览 · 2022-06-19 15:26:05

ACGkaka_ · 2022-06-19 15:26:05 发布

背景：在分布式服务架构下，一个 Web 请求从网关流入，有可能会调用多个服务对请求进行处理，拿到最终结果。在这个过程中每个服务之间的通信又是单独的网络请求，无论请求流经的哪个服务除了故障或者处理过慢都会对前端造成影响。

一、相关概念

在分布式链路追踪中有两个重要的概念：跟踪（trace）和跨度（span）。trace 是请求在分布式系统中的整个链路视图，span 则代表整个链路中不同服务内部的视图，span 组合在一起就是整个 trace 的视图。
traceId：用于标识某一次具体的请求ID。当用户的请求进入系统后，会在RPC调用网络的第一层生成一个全局唯一的traceId，并且会随着每一层的RPC调用，不断往后传递，这样的话通过traceId就可以把一次用户请求在系统中调用的路径串联起来。

spanId：：用于标识某一次RPC调用在分布式请求中的位置。请求到达每个服务后，服务都会为请求生成spanId。

parent-spanId：：用于标识上游RPC调用在分布式请求中的位置。请求到达每个服务后，随请求一起从上游传过来的上游服务的 spanId 会被记录成 parent-spanId，或者叫 pspanId。当前服务生成的 spanId 随着请求一起，在传到下游服务时，这个 spanId 又会被下游服务当作 parent-spanId 记录。
MDC：（Mapped Diagnostic Context）映射诊断环境，是 log4j 和 logback 提供的一种方便在线多线程条件下记录日志的功能，可以看成是一个与当前线程绑定的 ThreadLocal。
public class MDC {
    // 添加 key-value
    public static void put(String key, String val) {...}
    // 根据 key 获取 value
    public static String get(String key) {...}
    // 根据 key 删除映射
    public static void remove(String key) {...}
    // 清空
    public static void clear() {...}
}

二、设置过滤器

TraceContextFilter.java

package com.demo.filter;

import org.slf4j.MDC;
import org.springframework.web.filter.OncePerRequestFilter;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.UUID;

public class TraceContextFilter extends OncePerRequestFilter {

    @Override
    protected void doFilterInternal(HttpServletRequest httpServletRequest, HttpServletResponse httpServletResponse, FilterChain filterChain) throws ServletException, IOException {
        try {
            // 填充数据（适用logback、log4j 1.x）
            MDC.put("traceId", UUID.randomUUID().toString());
            // 填充数据（适用log4j 2.x）
            // ThreadContext.put(Contents.REQUEST_ID, UUID.randomUUID().toString());
            filterChain.doFilter(httpServletRequest, httpServletResponse);
        } finally {
            // 请求结束时清除数据，否则会造成内存泄露问题
            MDC.remove("traceId");
        }
    }
}

TraceFilterConfig.java（将过滤器注入到容器中）

import com.demo.filter.TraceContextFilter;
import org.springframework.boot.web.servlet.FilterRegistrationBean;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
public class TraceFilterConfig {

    @Bean
    public FilterRegistrationBean traceContextFilterRegistrationBean() {
        FilterRegistrationBean filterRegistrationBean = new FilterRegistrationBean();
        filterRegistrationBean.setFilter(new TraceContextFilter());
        filterRegistrationBean.addUrlPatterns("/*");
        return filterRegistrationBean;
    }
}

三、设置日志

在 log4j、logback中配置 %X{traceId}，即可在日志中打印traceId。

logback设置示例：

    <property name="CONSOLE_LOG_PATTERN"
              value="%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} [%clr(%X{traceId}){yellow},%clr(%X{X-B3-TraceId}){yellow}] %clr(%level){blue} %clr(%logger){cyan} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}"/>

logback打印示例：

2022-06-04 10:55:44.490 [aac50971c2aa464987d6309d2dda0781,] INFO org.apache.ibatis.logging.stdout.StdOutImpl Creating a new SqlSession
2022-06-04 10:55:44.496 [aac50971c2aa464987d6309d2dda0781,] INFO org.apache.ibatis.logging.stdout.StdOutImpl SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@6504bfe5] was not registered for synchronization because synchronization is not active
2022-06-04 10:55:44.508 [aac50971c2aa464987d6309d2dda0781,] INFO org.apache.ibatis.logging.stdout.StdOutImpl JDBC Connection [com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl@7deee750] will not be managed by Spring
2022-06-04 10:55:44.515 [aac50971c2aa464987d6309d2dda0781,] INFO org.apache.ibatis.logging.stdout.StdOutImpl ==>  Preparing: select * from t_user_info where id = ? limit 1
2022-06-04 10:55:44.695 [aac50971c2aa464987d6309d2dda0781,] INFO org.apache.ibatis.logging.stdout.StdOutImpl ==> Parameters: 111(String)
2022-06-04 10:55:44.737 [aac50971c2aa464987d6309d2dda0781,] INFO org.apache.ibatis.logging.stdout.StdOutImpl <==    Columns: ID, NAME, CREATE_TIME, UPDATE_TIME
2022-06-04 10:55:44.739 [aac50971c2aa464987d6309d2dda0781,] INFO org.apache.ibatis.logging.stdout.StdOutImpl <==        Row: 111, ACGkaka, 2022-06-02 19:10:55, 2022-06-02 20:54:33
2022-06-04 10:55:44.749 [aac50971c2aa464987d6309d2dda0781,] INFO org.apache.ibatis.logging.stdout.StdOutImpl <==      Total: 1
2022-06-04 10:55:44.752 [aac50971c2aa464987d6309d2dda0781,] DEBUG com.alibaba.druid.pool.PreparedStatementPool {conn-10001, pstmt-20000} enter cache