（Dubbo架構）基於MDC+Filter的跨應用分布式日志追蹤解決方案

 

在單體應用中，日志追蹤通常的解決方案是給日志添加 tranID（追蹤ID），生成規則因系統而異，大致效果如下：

 

查詢時只要使用 grep 命令進行追蹤id篩選即可查到此次調用鏈中所有日志，但是在 dubbo 分布式系統中，由於 tranID 底層存儲在 ThreadLocal 中，由於應用分布在不同的機器中，無法跨應用共享，同一鏈路多個應用之間的 tranID 不一致，出現線上問題時，日志的排查就尤為棘手。

 

先說結論：dubbo 分布式應用也可使用MDC進行分布式日志追蹤，但是需要配合dubbo提供的filter技術來實現，更細化的，如果想對系統無侵入加入追蹤日志，則可再配合攔截器對請求進行統一攔截，實現追蹤id自動生成，鏈路id自動傳遞，最終實現效果為任意系統日志的追蹤id即可獲取全系統全鏈路日志。

 

實現步驟：

定義 TraceUtil，該工具類主要作用為將操作MDC的步驟部分封裝，提供初始化鏈路、傳遞鏈路id、銷毀鏈路操作，即鏈路生命周期管理類。

import org.apache.commons.lang3.StringUtils;
import org.apache.dubbo.rpc.RpcContext;
import org.slf4j.MDC;

import java.util.UUID;

public class TraceUtil {

    public final static String TRACE_ID = "trace_id";
    public final static String TRACE_EXTENDED_INFO = "extended_info";


    public static void initTrace(String extendedInfo) {
        if (StringUtils.isBlank(MDC.get(TRACE_ID))) {
            String traceId = generateTraceId();
            setTraceId(traceId);
            MDC.put(TRACE_EXTENDED_INFO, extendedInfo);
        }
    }

    public static void getTraceFrom(RpcContext context) {
        String traceId = context.getAttachment(TRACE_ID);
        if (StringUtils.isNotBlank(traceId)) {
            setTraceId(traceId);
        }
        String uri = context.getAttachment(TRACE_EXTENDED_INFO);
        if (StringUtils.isNotEmpty(uri)) {
            MDC.put(TRACE_EXTENDED_INFO, uri);
        }
    }

    public static void putTraceInto(RpcContext context) {
        String traceId = MDC.get(TRACE_ID);
        if (StringUtils.isNotBlank(traceId)) {
            context.setAttachment(TRACE_ID, traceId);
        }

        String uri = MDC.get(TRACE_EXTENDED_INFO);
        if (StringUtils.isNotBlank(uri)) {
            context.setAttachment(TRACE_EXTENDED_INFO, uri);
        }
    }

    public static void clearTrace() {
        MDC.clear();
    }

    private static void setTraceId(String traceId) {
        traceId = StringUtils.left(traceId, 36);
        MDC.put(TRACE_ID, traceId);
    }

    private static String generateTraceId() {
        return UUID.randomUUID().toString();
    }
}

 

DubboRequestDTO 和 DubboResponseDTO 定義如下：

@Data
public class DubboRequestDTO implements Serializable {
    private String interfaceClass;
    private String methodName;
    private Object[] args;
}


@Data
public class DubboResponseDTO implements Serializable {
    private String interfaceClassName;
    private String methodName;
    private String result;
    private long spendTime;
}

定義Dubbo Filter，如下，該類為 Dubbo Filter 接口實現類，主要作用為傳遞追蹤ID，打印追蹤日志

package com.serviceshare.component.tracking;

import com.alibaba.fastjson.JSON;
import lombok.extern.slf4j.Slf4j;
import org.apache.dubbo.common.extension.Activate;
import org.apache.dubbo.registry.Constants;
import org.apache.dubbo.rpc.*;

import java.io.File;
import java.io.InputStream;
import java.util.Arrays;

@Slf4j
@Activate(order = 999, group = {Constants.PROVIDER_PROTOCOL, Constants.CONSUMER_PROTOCOL})
public class DubboTraceFilter implements Filter {

    private static final int SLOW_METHOD_THRESHOLD = 3000;

    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
        // 處理 Trace 信息
        printRequest(invocation);
        // 執行前
        handleTraceId();
        long start = System.currentTimeMillis();
        Result result = invoker.invoke(invocation);
        long end = System.currentTimeMillis();
        // 執行后
        final long executionTime = end - start;
        printResponse(invocation, result, executionTime);
        return result;
    }


    private void printRequest(Invocation invocation) {
        DubboRequestDTO requestDTO = new DubboRequestDTO();
        requestDTO.setInterfaceClass(invocation.getInvoker().getInterface().getName());
        requestDTO.setMethodName(invocation.getMethodName());
        requestDTO.setArgs(getArgs(invocation));
        log.info("RPC請求開始 , {}", requestDTO);
    }


    private void printResponse(Invocation invocation, Result result, long spendTime) {
        DubboResponseDTO responseDTO = new DubboResponseDTO();
        responseDTO.setInterfaceClassName(invocation.getInvoker().getInterface().getName());
        responseDTO.setMethodName(invocation.getMethodName());
        responseDTO.setResult(JSON.toJSONString(result.getValue()));
        responseDTO.setSpendTime(spendTime);
    }

    private Object[] getArgs(Invocation invocation) {
        Object[] args = invocation.getArguments();
        args = Arrays.stream(args).filter(arg -> {
            // 過濾大參
            if (arg instanceof byte[] || arg instanceof Byte[] || arg instanceof InputStream || arg instanceof File) {
                return false;
            }
            return true;
        }).toArray();
        return args;
    }

    private void handleTraceId() {
        RpcContext context = RpcContext.getContext();
        if (context.isConsumerSide()) {
            TraceUtil.putTraceInto(context);
        } else if (context.isProviderSide()) {
            TraceUtil.getTraceFrom(context);
        }
    }
}

 

啟用Filter，Dubbo 采用 SPI 擴展方式，啟用我們自己編寫的 Filter ，非常方便，只需要在 classpath 路徑下 META-INF 文件夾下新建 com.alibaba.dubbo.rpc.Filter 文件引入以下內容即可

（注意，包名替換為自己定義的 Filter 類包名）

com.serviceshare.component.tracking.DubboTraceFilter

 

修改 logback 配置文件 pattern，添加 extended_info 和 trace_id

<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS}[%X{extended_info}][%X{trace_id}][%thread] %-5level %logger{50}:%L - %msg%n</pattern>

 

嘗試在啟動類插樁測試

 

  public static void main(String[] args) throws UnknownHostException {
    TraceUtil.initTrace("START-APP");
    SpringApplication.run(SysApplication.class, args);
  }

 

 

 

啟動項目，查看效果

 

 

 

 

多個系統都按照上述配置配置后，即可實現日志鏈路追蹤，這樣屬於半侵入式集成，因為每個“入口”都需要手動插樁初始化鏈路，對系統所有已有接口造成了代碼侵入，肯定有更完美的方案，那就是最終實現方案，無侵入式集成，怎么做？

 

首先，入口，不一定是 web 接口等一系列由內外部觸發程序代碼運行的點，都可以稱為入口。還可能是定時任務，所以如果要保證每條日志都有跡可循的話，需要保證外部觸發和內部觸發的操作都要初始化MDC，Spring 提供的AOP+攔截器剛好可以實現這一點，借助攔截器我們攔截所有系統請求，在系統進入系統入口時，初始化鏈路，后續一系列調用自然而然都記錄了追蹤ID。

 

定時任務屬於系統調度內部觸發，同一定時任務如果不分片不會跨系統，但是也需要追蹤日志，可以使用 Spring 提供的 AOP 進行定時任務注解定點攔截，實現定時任務執行前插樁，執行完畢后拆樁。

 

web請求自動插樁攔截器實現：

import org.springframework.context.annotation.Configuration;
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;

/**
 * web請求鏈路追蹤攔截器
 *
 * @author shaozhengmao
 * @create 2021-05-26 1:10 下午
 * @desc
 */
@Configuration
public class TraceWebFilter extends OncePerRequestFilter {

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
        TraceUtil.initTrace(request.getRequestURI());
        filterChain.doFilter(request, response);
        TraceUtil.clearTrace();
    }
}

 

 

該類實現了 JavaEE 提供的 Filter 接口，即過濾器，對所有web請求進行攔截，前置設置追蹤元信息，后置清空追蹤元信息，實現了 web 請求全鏈路追蹤，為什么不使用 Spring 提供的 WebMvcConfigurer 接口？如果使用 WebMvcConfigurer 接口，請求失敗的情況下，追蹤ID會丟失，可自行測試。

 

定時任務自動插樁實現：

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.reflect.MethodSignature;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;

import java.lang.reflect.Method;

/**
 * 定時任務鏈路追蹤攔截器
 * @author shaozhengmao
 * @create 2021-05-26 1:32 下午
 * @desc
 */
@Aspect
@Component
@Order(1)
public class TraceTaskConfigurer {

    @Around("@annotation(org.springframework.scheduling.annotation.Scheduled)")
    public Object verifyRoleExecuteCommand(ProceedingJoinPoint pjp) throws Throwable {
        // 獲取當前攔截方法的對象
        MethodSignature msig = (MethodSignature) pjp.getSignature();
        Method targetMethod = pjp.getTarget().getClass().getDeclaredMethod(msig.getName(), msig.getMethod().getParameterTypes());
        try {
            TraceUtil.initTrace(targetMethod.getName());
            return pjp.proceed();
        } finally {
            TraceUtil.clearTrace();
        }
    }
}

 

 

 

和鏈路追蹤系統集成，SkyWlaking 提供了分布式鏈路追蹤技術，當集成 SkyWlaking 后，可使用 SkyWlaking 的追蹤id來初始化日志追蹤id，這樣既可無縫和 SkyWlaking 集成，從而實現，分布式調用鏈路追蹤+分布式鏈路調用日志深度集成。

 

分布式追蹤日志有什么好處，對於生產環境開發or運維人員排查錯誤有極大的幫助，可以很方便的找到一個請求完整的請求鏈路日志，當然，對於日志的探索，遠不止此，隨着系統的龐大，肯定會選擇更好的處理方式，比如ELK，而分布式追蹤ID對於集成 ELK 也提供了非常好的幫助。

 

集成步驟總結：

1.classpath 新增 /META-INF/dubbo/com.alibaba.dubbo.rpc.Filter 內容 com.emax.zhenghe.common.tracking.DubboTraceFilter

2.Spring掃描包新增 "com.emax.zhenghe.common.tracking"

3.logback 打印模板新增 [%X{extended_info}][%X{trace_id}]

 

最終效果

系統1：

 

 系統2：

 

 

 

千里之行，始於足下