自研dubbo traceId和spanId 实现

    公司项目采用SpringBoot+dubbo技术栈,虽然上了elk,但是还是不能把所有的日志串联起来。因此自己写了一套traceId和spanId的生成方案。在此记录下该方案的具体实现,方便后续查阅

一、 名词解释

    traceId:链路Id
    spanId:可以理解为服务Id,一各请求可能会调用多个服务,调用一个服务产生一个新的spanId

二、 方案介绍

2.1  traceId实现

    1. 请求都是从web打过来的,所web的filter拦截,生成一个traceId并put到MDC中
    2. dubbo消费者filter负责把调用链的MDC内容传递给生产者,即放到attachMent里面
    3. dubbo生产者filter负责把attachMent里面的内容取出并放到MDC中

2.2 spanId的实现

    1. 引入一个logicId
    2. logicId放在dubbo的消费者拦截器里面累加
    3. 当同一个业务调用多次生产者时,则消费者里面的logicId会自增并传递到生产者

三、 实现思路

3.1 web过滤器实现功能

     doFilter前: 
             生成traceId;  
             生成 spanId;   
             生成一个logicId,默认值为0;
             存到MDC
     doFilter后:
            清除MDC相关内容

3.2 dubbo消费者    

    invoke前:
        (1)累加logicId
        (2)将traceId和spanId及logicId传递到 生产者

3.3 dubbo生产者

    invoke前:
        (1)将traceId放到MDC中
        (2)取出spanId和logicId,用.拼接在一起生成一个新的spanId放到MDC中
        (3)生成一个logicId,默认值为0 存到mdc中
    invoke后:
        清除MDC相关内容
说明:
    其实dubbo生产者这过滤器和web过滤器是差不多的东西。他们都需要生成当前应用的logicId

四、 实现代码和效果

(1)TraceUtil

package com.cybermax.vaccine.logtrace;

import org.apache.commons.lang.StringUtils;
import org.slf4j.MDC;
import java.util.UUID;
import static com.cybermax.vaccine.logtrace.TraceConstants.*;

public class TraceUtil {


    /**
     * description: httpFilter的方式初始化MDC,会返回traceId
     * @param traceId
     * @return String
     * @author ZENG.XIAO.YAN
     * @time 2021-01-30 20:01
     */
    public static String initMDCWithHttpFilter(String traceId) {
        String val = StringUtils.defaultIfBlank(traceId, generateTraceId());
        MDC.put(TRACE_ID, val);
        MDC.put(SPAN_ID, "0");
        MDC.put(LOGIC_ID, "0");
        return val;
    }

    /**
     * logicId +1
     * @param logicId
     * @return
     */
    public static String incrLogicId(String logicId) {
        return String.valueOf(Integer.parseInt(logicId) + 1);
    }


    /**
     * 从 MDC 中清除当前线程的 Trace信息
     */
    public static void clearMDC() {
        MDC.clear();
    }


    /**
     * 生成traceId
     * @return  链路ID
     */
    public static String generateTraceId() {
        return UUID.randomUUID().toString();
    }

    /**
     * 生成新的spanId
     * @param spanId
     * @param logicId
     * @return
     */
    public static String getNewSpanId(String spanId, String logicId) {
        return new StringBuilder(spanId).append(".").append(logicId).toString();
    }
}

(2)TraceConstants

package com.cybermax.vaccine.logtrace;

/**
 * TraceConstants
 *
 * @author ZENG.XIAO.YAN
 * @version 1.0
 * @Date 2021-01-30
 */
public class TraceConstants {
    /**
     * 追踪id
     */
    public static final String TRACE_ID = "traceId";

    /**
     * 分段ID
     * 同一个调用链下的分段调用ID
     * 对于前端收到请求,生成的spanId固定都是0
     * 签名方式生成:0, 0.1, 0.1.1, 0.2
     */
    public static final String SPAN_ID = "spanId";
    /**
     * 逻辑ID
     * 同一个分段调用下的业务逻辑ID
     * 标识服务内部的调用顺序
     */
    public static final String LOGIC_ID = "logicId";


}

(3) LogTraceHttpFilter

package com.cybermax.vaccine.logtrace;
import lombok.extern.slf4j.Slf4j;
import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;

@Slf4j
public class LogTraceHttpFilter implements Filter {
    private static final String TRACE_ID_HEAD = "ZTraceId";

    @Override
    public void init(FilterConfig filterConfig) {
        // TODO Auto-generated method stub
    }

    @Override
    public final void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
        try {
            // 这个traceId也可以考虑从Http请求里面取,如果是null则默认用uuid
            HttpServletRequest request = (HttpServletRequest) servletRequest;
            HttpServletResponse response = (HttpServletResponse) servletResponse;
            String traceId = TraceUtil.initMDCWithHttpFilter(getTraceId(request));
            // 响应头里面添加一个traceId,方便f12debug调试;本来是每个ajax都由前端生成traceId,由于改动成本太高,就变成响应输出traceId
            response.setHeader(LogTraceHttpFilter.TRACE_ID_HEAD, traceId);
            if (log.isInfoEnabled()) {
                log.info("web端接收http请求[{}]----start", request.getRequestURI());
            }
            filterChain.doFilter(request, response);
        } finally {
            // 最后清除掉MDC内容
            TraceUtil.clearMDC();
        }
    }

    @Override
    public void destroy() {
    }

    /**
     * description: 由于考虑到和其他系统对接时,可能会用其他系统传递进来参数作为traceId
     *  因此预留此方法方便后续Override
     * @return java.lang.String
     * @author ZENG.XIAO.YAN
     * @time 2021-01-30 20:04
     */
    public String getTraceId(ServletRequest servletRequest) {
        return null;
    }

}

(4)LogTraceConsumerFilter

package com.cybermax.vaccine.logtrace;
import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang3.StringUtils;
import org.apache.dubbo.common.constants.CommonConstants;
import org.apache.dubbo.common.extension.Activate;
import org.apache.dubbo.rpc.*;
import org.slf4j.MDC;
import java.util.Map;

@Slf4j
@Activate(group = CommonConstants.CONSUMER)
public class LogTraceConsumerFilter implements Filter {

    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
        // 消费者负责把调用链端的MDC信息传递到生产者
        String traceId = MDC.get(TraceConstants.TRACE_ID);
        String spanId = MDC.get(TraceConstants.SPAN_ID);
        String logicId = MDC.get(TraceConstants.LOGIC_ID);
        if (StringUtils.isNotBlank(traceId) && StringUtils.isNotBlank(spanId) && StringUtils.isNotBlank(logicId)) {
            // 逻辑Id+1
            String newLogicId = TraceUtil.incrLogicId(logicId);
            MDC.put(TraceConstants.LOGIC_ID, newLogicId);
            // 传递traceId spanId logicId
            Map<String, String> attachments = invocation.getAttachments();
            attachments.put(TraceConstants.TRACE_ID, traceId);
            attachments.put(TraceConstants.SPAN_ID, spanId);
            attachments.put(TraceConstants.LOGIC_ID, newLogicId);
        }
        return invoker.invoke(invocation);
    }
}

(5)LogTraceProviderFilter

package com.cybermax.vaccine.logtrace;

import lombok.extern.slf4j.Slf4j;
import org.apache.commons.collections4.MapUtils;
import org.apache.commons.lang3.StringUtils;
import org.apache.dubbo.common.constants.CommonConstants;
import org.apache.dubbo.common.extension.Activate;
import org.apache.dubbo.rpc.*;
import org.slf4j.MDC;
import java.util.Map;


@Slf4j
@Activate(group = CommonConstants.PROVIDER)
public class LogTraceProviderFilter implements Filter {

    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {

        try {
            // 生产者负责把信息放进MDC里面
            Map<String, String> attachments = invocation.getAttachments();
            String traceId = MapUtils.getString(attachments, TraceConstants.TRACE_ID);
            String spanId = MapUtils.getString(attachments,TraceConstants.SPAN_ID);
            String logicId = MapUtils.getString(attachments,TraceConstants.LOGIC_ID);
            if (StringUtils.isNotBlank(traceId) && StringUtils.isNotBlank(spanId) && StringUtils.isNotBlank(logicId)) {
                // 生成新的spanId
                String newSpanId = TraceUtil.getNewSpanId(spanId, logicId);
                MDC.put(TraceConstants.TRACE_ID, traceId);
                MDC.put(TraceConstants.SPAN_ID, newSpanId);
                MDC.put(TraceConstants.LOGIC_ID, "0");
            }
            if (log.isInfoEnabled()) {
                log.info("dubbo服务执行dubbo方法{}.{}", invoker.getInterface().getName(), invocation.getMethodName());
            }
            Result result = invoker.invoke(invocation);
            return result;
        } finally {
            TraceUtil.clearMDC();
        }
    }
}

(6)配置dubbo的spi扩展

(7)日志中输出TraceId和SpanId

        下面只要关注traceId和SpanId的取值,具体的格式自己搞定
<?xml version="1.0" encoding="UTF-8"?>
<!--
 默认file appender的encoder输出json时总是有点问题,因此引入logstash-logback-encoder来改变这一现状
-->

<included>
    <appender name="FILE"
              class="ch.qos.logback.core.rolling.RollingFileAppender">
        <encoder
                class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
            <providers>
                <!--<timestamp>-->
                    <!--<timeZone>UTC</timeZone>-->
                <!--</timestamp>-->
                <pattern>
                    <!--可以直接从apollo中取值-->
                    <pattern>
                        {"time":"%d{yyyy-MM-dd'T'HH:mm:ss.SSS+08:00}",
                        "systemName":"%property{systemName}" ,
                        "level": "%level",
                        "traceId": "%X{traceId}",
                        "spanId": "%X{spanId}",
                        "context": "%t [%c] - %m ",
                        "exceptionTrace":"%exception{50}"
                        }%n
                    </pattern>
                </pattern>
            </providers>
        </encoder>
        <file>${LOG_FILE}</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE}.%d{yyyy-MM-dd}.%i.gz</fileNamePattern>
            <maxFileSize>${LOG_FILE_MAX_SIZE:-100MB}</maxFileSize>
            <maxHistory>${LOG_FILE_MAX_HISTORY:-0}</maxHistory>
        </rollingPolicy>
    </appender>
</included>
    

(8)输出的日志文件效果举例

    下面为程序里面输出的一条日志,为了filebeat收集后不用自己写语法去解析日志,我配置成了json格式;这不是重点,重点是下面这个json
{
    "time":"2021-09-10T17:15:53.285+08:00",
    "systemName":"vaccine-service-app",
    "level":"INFO",
    "traceId":"c2348f26-0ca6-4772-83a3-de7b7cb1aa9d",
    "spanId":"0.2",
    "context":"DubboServerHandler-192.168.199.42:20880-thread-199 [com.cybermax.service.realize.hession.bacterin.BacterinFCServiceImpl] - 已命中[REDIS_DEL_allBacterinMap_bactCode]缓存... ",
    "exceptionTrace":""
}
  
效果案例二
下面再贴一张图,这个的日志格式就不是json了,只在原来的springboot的日志格式中添加了traceId和spanId
配置的日志格式为:
${CONSOLE_LOG_PATTERN:%clr(%d{${LOG_DATEFORMAT_PATTERN:yyyy-MM-dd'T'HH:mm:ss.SSS+08:00}}){faint} %clr(${LOG_LEVEL_PATTERN:%5p}) %clr(${PID:- }){magenta} %clr([%X{traceId}] [%X{spanId}]){yellow} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:%wEx}}
效果为:

五、总结

  • 重点关注spanId的实现,traceId实现比较简单
  • 这个spanId生成后就和阿里鹰眼的效果差不多
  • 这个traceId和spanId如果输出到日志时,可以直接发送到logstash,也可以生成日志文件再用其他filebeat去收集

六、参考链接

    《链路追踪的时候,链路id是怎么管理的》 https://blog.csdn.net/qq_37286668/article/details/107292491
    《Dubbo日志链路追踪TraceId选型》 https://blog.csdn.net/zlt2000/article/details/108820788
    《阿里巴巴鹰眼系统了解》https://blog.csdn.net/yongshenghuang/article/details/93490207

posted @ 2021-10-26 23:42  zeng1994  阅读(1217)  评论(0编辑  收藏  举报