undefined

前言

前段時(shí)間吧雹，本人一直協(xié)助項(xiàng)目組在做系統(tǒng)的重構(gòu)骨杂，系統(tǒng)應(yīng)用被拆分成了多個(gè)服務(wù)，部分服務(wù)做了集群部署雄卷。隨著上述架構(gòu)的演進(jìn)腊脱，自然而然的引進(jìn)了ELK + Filebeat 做日志收集。但是在使用Kibana查看日志時(shí)龙亲，由于缺少TraceID陕凹，導(dǎo)致開(kāi)發(fā)人員很難篩選出指定請(qǐng)求的相關(guān)日志，也很難追蹤應(yīng)用對(duì)下游服務(wù)的調(diào)用過(guò)程鳄炉，耗費(fèi)了很多時(shí)間杜耙。我自己查過(guò)幾次問(wèn)題之后，實(shí)在受不了每次要花這么久的時(shí)間拂盯，就趕緊向主管提了這一次的改造佑女。

本篇文章主要是記錄本人對(duì)項(xiàng)目TraceID鏈路追蹤改造的解決方案的研究、遇到的問(wèn)題和具體的實(shí)現(xiàn)谈竿，同時(shí)本次改造也加深了我自己對(duì)分布式服務(wù)追蹤的一些理解团驱，我也寫(xiě)在了里面。

本文主要內(nèi)容：

• 初步實(shí)現(xiàn)
• 異步線程traceId丟失的問(wèn)題
• 面向 Dubbo RPC 鏈路追蹤
• 面向 HTTP Service 鏈路追蹤
• 思考 SpringCloud Sleuth 的實(shí)現(xiàn)
• 小結(jié)

一空凸、初步實(shí)現(xiàn)

大體的思路就是借助slf4j的MDC功能 + Spring Interceptor嚎花，當(dāng)外部請(qǐng)求進(jìn)入時(shí)生成一個(gè)traceId放在MDC當(dāng)中。

MDC

這里簡(jiǎn)單介紹一下MDC呀洲。

MDC（Mapped Diagnostic Context紊选，映射調(diào)試上下文）是 log4j 和 logback 提供的一種方便在多線程條件下記錄日志的功能。MDC 可以看成是一個(gè)與當(dāng)前線程綁定的Map道逗，可以往其中添加鍵值對(duì)兵罢。MDC 中包含的內(nèi)容可以被同一線程中執(zhí)行的代碼所訪問(wèn)。當(dāng)前線程的子線程會(huì)繼承其父線程中的 MDC 的內(nèi)容滓窍。當(dāng)需要記錄日志時(shí)卖词，只需要從 MDC 中獲取所需的信息即可。MDC 的內(nèi)容則由程序在適當(dāng)?shù)臅r(shí)候保存進(jìn)去吏夯。對(duì)于一個(gè) Web 應(yīng)用來(lái)說(shuō)此蜈，通常是在請(qǐng)求被處理的最開(kāi)始保存這些數(shù)據(jù)。

簡(jiǎn)單來(lái)說(shuō)锦亦，MDC就是日志框架提供的一個(gè)InheritableThreadLocal舶替，項(xiàng)目代碼中可以將鍵值對(duì)放入其中令境，在打印的時(shí)候從ThreadLocal中獲取到對(duì)應(yīng)的值然后打印出來(lái)杠园。詳細(xì)的原理本文就不贅述了√蚴看下 log4j 和 logback 里面的實(shí)現(xiàn)類就知道了抛蚁。

實(shí)現(xiàn)

1. 自定義Spring 攔截器 TraceInterceptor

/**
 * @author Richard_yyf
 */
public class TraceInterceptor extends HandlerInterceptorAdapter {

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        // 清空
        MDC.clear();

        ThreadMdcUtil.setTraceIdIfAbsent();

        //后續(xù)邏輯... ...
        return true;
    }
}

2. 注冊(cè) 攔截器

/**
 * @author Richard_yyf
 */
@Configuration
public class WebMvcConfig implements WebMvcConfigurer {

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(traceInterceptor())
                .addPathPatterns("/**")
                .order(0);
    }

    @Bean
    public TraceInterceptor traceInterceptor() {
        return new TraceInterceptor();
    }

}

ThreadMdcUtil是我自己封裝的一個(gè)工具類陈醒，包裝了對(duì) TraceId 的一些操作：

public class ThreadMdcUtil {
    
    public static String createTraceId() {
        String uuid = UUID.randomUUID().toString();
        return DigestUtils.md5Hex(uuid).substring(8, 24);
    }

    public static void setTraceIdIfAbsent() {
        if (MDC.get(TRACE_ID) == null) {
            MDC.put(TRACE_ID, createTraceId());
        }
    }
    // 省略了一些方法在后面會(huì)展示出來(lái)
}

DigestUtils來(lái)自于第三方依賴：

<dependency>
    <groupId>commons-codec</groupId>
    <artifactId>commons-codec</artifactId>
    <version>***</version>
</dependency>

TRACE_ID放在 Constant類中方便引用：

public class Constant {
    ...
   public static final String TRACE_ID = "traceId";
    ...
}

3. 在日志配置文件中修改輸出格式说墨，增加TraceID字段的打印

   取值方式：%X{traceid}

image.png

結(jié)果

通過(guò)上面的步驟之后超升，你的web應(yīng)用接收到請(qǐng)求后打印的日志就會(huì)帶上TraceId萌朱。

image.png

二膝藕、遇上線程池 TraceID 丟失的問(wèn)題

前面的方案只是簡(jiǎn)單實(shí)現(xiàn)了我們的最基礎(chǔ)的需求耐亏。但是如果你真的使用起來(lái)货徙，會(huì)發(fā)現(xiàn)異步的任務(wù)線程是沒(méi)有獲取到TraceID的胚委。

一個(gè)成熟的應(yīng)用肯定會(huì)用到很多的線程池竹椒。常見(jiàn)的有@Async異步調(diào)用的線程池朦促，應(yīng)用自身定義的一些線程池等等膝晾。

前面有稍微提到過(guò)，MDC是通過(guò)InheritableThreadLocal實(shí)現(xiàn)的务冕，創(chuàng)建子線程時(shí)血当，會(huì)復(fù)制父線程的inheritableThreadLocals屬性。但是在線程池中禀忆，線程是復(fù)用的臊旭，而不是新創(chuàng)建的，所以MDC內(nèi)容就無(wú)法傳遞進(jìn)去箩退。

所以我們就需要曲線救國(guó)离熏，既然線程是復(fù)用的，那我們理所當(dāng)然的就能想到在任務(wù)提交至線程池的時(shí)候做一些“騷”操作戴涝，來(lái)講MDC的內(nèi)容傳遞下去撤奸。

改造

這里就直接放上代碼：

/**
 * @author Richard_yyf
 */
public class ThreadMdcUtil {
    
    public static String createTraceId() {
        String uuid = UUID.randomUUID().toString();
        return DigestUtils.md5Hex(uuid).substring(8, 24);
    }

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

    public static void setTraceId() {
        MDC.put(TRACE_ID, createTraceId());
    }

    public static void setTraceId(String traceId) {
        MDC.put(TRACE_ID, traceId);
    }

    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();
            }
        };
    }

    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();
            }
        };
    }
}

自己包裝擴(kuò)展 ThreadPoolExecutor

/**
 * @author Richard_yyf
 */
public class ThreadPoolExecutorMdcWrapper extends ThreadPoolExecutor {

    public ThreadPoolExecutorMdcWrapper(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit,
                                        BlockingQueue<Runnable> workQueue) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
    }

    public ThreadPoolExecutorMdcWrapper(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit,
                                        BlockingQueue<Runnable> workQueue, ThreadFactory threadFactory) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory);
    }

    public ThreadPoolExecutorMdcWrapper(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit,
                                        BlockingQueue<Runnable> workQueue, RejectedExecutionHandler handler) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, handler);
    }

    public ThreadPoolExecutorMdcWrapper(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit,
                                        BlockingQueue<Runnable> workQueue, ThreadFactory threadFactory,
                                        RejectedExecutionHandler handler) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory, handler);
    }

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

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

    @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()));
    }
}

使用

具體的使用就是把你原來(lái)executor = new ThreadPoolExecutor(...)改成executor = new ThreadPoolExecutorMdcWrapper(...)即可。

比如你是用Spring @Async異步方法的喊括，在配置線程池的時(shí)候就這樣聲明：

@SpringBootApplication
public class Application {

    public static void main(String[] args) {
        SpringApplication.run(Application.class, args);
    }

    @EnableAsync
    @Configuration
    class TaskPoolConfig {

        @Bean("taskExecutor")
        public Executor taskExecutor() {
            ThreadPoolTaskExecutor executor = new ThreadPoolExecutorMdcWrapper();
            executor.setCorePoolSize(10);
            executor.setMaxPoolSize(20);
            executor.setQueueCapacity(200);
            executor.setKeepAliveSeconds(60);
            return executor;
        }
    }

}

結(jié)果

按照上述步驟胧瓜，你的異步任務(wù)在打印日志的時(shí)候，就會(huì)帶上原本請(qǐng)求的TraceID了郑什。

image.png

三府喳、面向 Dubbo RPC 鏈路追蹤

我們項(xiàng)目組主要使用Dubbo進(jìn)行微服務(wù)框架的開(kāi)發(fā)。我們想在服務(wù)調(diào)用之間蘑拯，傳遞上游服務(wù)的TraceID钝满，來(lái)達(dá)到鏈路追蹤的效果。

Dubbo 提供了這樣的機(jī)制申窘，可以通過(guò)Dubbo RPC + Dubbo Filter 來(lái)設(shè)置和傳遞消費(fèi)者的TraceID弯蚜。

詳見(jiàn)官網(wǎng)對(duì)于這兩個(gè)概念的說(shuō)明。

Dubbo RPC
Dubbo Filter

這邊我直接給出代碼和擴(kuò)展點(diǎn)配置剃法。

Dubbo Filter for Consumer

消費(fèi)者應(yīng)用端：

/**
 * @author Richard_yyf
 */
@Activate(group = {Constants.CONSUMER})
public class ConsumerRpcTraceFilter implements Filter {

    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
        //如果MDC上下文有追蹤ID碎捺，則原樣傳遞給provider端
        String traceId = MDC.get(TRACE_ID);
        if (StringUtils.isNotEmpty(traceId)) {
            RpcContext.getContext().setAttachment(TRACE_ID, traceId);
        }
        return invoker.invoke(invocation);
    }

}

SPI 配置：

在resources目錄下，創(chuàng)建/META-INF/dubbo/com.alibaba.dubbo.rpc.Filter文件.

consumerRpcTraceFilter=com.xxx.xxx.filter.ConsumerRpcTraceFilter

image.png

Dubbo Filter for Provider

服務(wù)提供者應(yīng)用端：

/**
 * @author Richard_yyf
 */
@Activate(group = {Constants.PROVIDER})
public class ProviderRpcTraceFilter implements Filter {
    
    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
        // 接收消費(fèi)端的traceId
        String traceId = RpcContext.getContext().getAttachment(TRACE_ID);
        if (StringUtils.isBlank(traceId)) {
            traceId = ThreadMdcUtil.createTraceId();
        }

        // 設(shè)置日志traceId
        ThreadMdcUtil.setTraceId(traceId);

        // TODO 如果這個(gè)服務(wù)還會(huì)調(diào)用下一個(gè)服務(wù)，需要再次設(shè)置下游參數(shù)
        // RpcContext.getContext().setAttachment("trace_id", traceId);

        try {
            return invoker.invoke(invocation);
        } finally {
            // 調(diào)用完成后移除MDC屬性
            MDC.remove(TRACE_ID);
        }
    }

}

SPI 配置：

providerRpcTraceFilter=com.xxx.xxx.filter.ProviderRpcTraceFilter

四收厨、面向 HTTP Service 鏈路追蹤

除了Dubbo RPC 的這種方式晋柱，常見(jiàn)微服務(wù)之間的調(diào)用也有通過(guò) HTTP REST 來(lái)完成調(diào)用的。這種場(chǎng)景下就需要在上游服務(wù)在發(fā)起HTTP調(diào)用的時(shí)候自動(dòng)將 TraceID添加到 HTTP Header 中诵叁。

以常用的 Spring RestTemplate 為例雁竞，使用攔截器來(lái)包裝 HTTP Header。

        RestTemplate restTemplate = new RestTemplate();

        List<ClientHttpRequestInterceptor> list = new ArrayList<>();
        list.add((request, body, execution) -> {
            String traceId = MDC.get(TRACE_ID);
            if (StringUtils.isNotEmpty(traceId)) {
                request.getHeaders().add(TRACE_ID, traceId);
            }
            return execution.execute(request, body);
        });

        restTemplate.setInterceptors(list);

下游服務(wù)由于是通過(guò)HTTP 接口暴露的服務(wù)拧额，就添加一個(gè)攔截器來(lái)獲取就好碑诉。

public class TraceInterceptor extends HandlerInterceptorAdapter {

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
        MDC.clear();
        String traceId = request.getHeader(TRACE_ID);
        if (StringUtils.isEmpty(traceId)) {
            ThreadMdcUtil.setTraceId();
        } else {
            MDC.put(TRACE_ID, traceId);
        }
        return true;
    }
}

五、思考 Spring Cloud Sleuth 的實(shí)現(xiàn)

經(jīng)過(guò)上面的幾個(gè)步驟侥锦，我們相當(dāng)于是自己形成了一個(gè)比較基礎(chǔ)的服務(wù)追蹤的解決方案联贩。

Spring Cloud 作為一個(gè)一站式 微服務(wù)開(kāi)發(fā)框架，提供了Spring Cloud Sleuth 作為 該技術(shù)體系下分布式跟蹤的解決方案捎拯。這里我想拿出來(lái)講一講泪幌。

Sleuth 是一個(gè)成熟的技術(shù)解決方案，基于 Google Dapper 為理論基礎(chǔ)實(shí)現(xiàn)署照，里面的一些術(shù)語(yǔ)都來(lái)自于那篇論文祸泪。在對(duì)于TraceID傳遞的問(wèn)題上，我們上面講的簡(jiǎn)單版的解決方案的一些解決問(wèn)題的思路建芙，實(shí)際上在Sleuth 中也有體現(xiàn)没隘。

首先就是分布式追蹤，Sleuth 會(huì)將 SpanID 和 TraceID添加到 Slf4J MDC 中禁荸，這樣在打印出來(lái)的日志就會(huì)有帶上對(duì)應(yīng)的標(biāo)識(shí)右蒲。

在遇到線程池 TraceID 傳遞失效的問(wèn)題時(shí)，我們相當(dāng)了對(duì)提交任務(wù)的操作進(jìn)行包裝赶熟，而在Slueth 中瑰妄，是通過(guò)實(shí)現(xiàn)HystrixConcurrencyStrategy接口來(lái)解決 TraceID異步傳遞的問(wèn)題。Hystrix在實(shí)際調(diào)用時(shí)映砖，會(huì)調(diào)用HystrixConcurrencyStrategy的 wrapCallable 方法间坐。通過(guò)實(shí)現(xiàn)這個(gè)接口，在wrapCallable 中將TraceID存放起來(lái)（具體參見(jiàn)SleuthHystrixConcurrencyStrategy）邑退。

在面對(duì)Dubbo RPC 的調(diào)用方式和 Http Service 的調(diào)用方式中竹宋，我們通過(guò)Dubbo RpcContext + Filter和 Http Header + Interceptor 的方式，通過(guò)協(xié)議或者框架本身提供的擴(kuò)展點(diǎn)和上下文機(jī)制地技，來(lái)傳遞TraceID蜈七。而在 Spring Cloud Sleuth中追蹤@Async,RestTemplate,Zuul,Feign等組件時(shí)，也是類似的解決思路莫矗。比如追蹤RestTemplate就是和上文一樣借用了Spring Client的 Interceptor 機(jī)制 （@See TraceRestTemplateInterceptor）飒硅。

上述就是將我們的簡(jiǎn)單解決方案和 Spring Cloud Sleuth 的對(duì)比砂缩，想說(shuō)明日志追蹤的思想和一些技術(shù)解決思路是共通相近的。

當(dāng)然狡相，Spring Cloud Sleuth 基于 Dapper 實(shí)現(xiàn)梯轻，提供了一個(gè)比較成熟的分布式系統(tǒng)調(diào)用追蹤架構(gòu)食磕，集成ZipKin + spring-cloud-sleuth-zipkin 依賴之后尽棕，能夠搭建一個(gè)完整的具有數(shù)據(jù)收集、數(shù)據(jù)存儲(chǔ)和數(shù)據(jù)展示功能的分布式服務(wù)追蹤系統(tǒng)彬伦。

通過(guò)Sleuth可以很清楚的了解到一個(gè)服務(wù)請(qǐng)求經(jīng)過(guò)了哪些服務(wù)滔悉，每個(gè)服務(wù)處理花費(fèi)了多長(zhǎng)。從而讓我們可以很方便的理清各微服務(wù)間的調(diào)用關(guān)系单绑。此外Sleuth可以幫助我們：

• 耗時(shí)分析: 通過(guò)Sleuth可以很方便的了解到每個(gè)采樣請(qǐng)求的耗時(shí)回官，從而分析出哪些服務(wù)調(diào)用比較耗時(shí);
• 可視化錯(cuò)誤: 對(duì)于程序未捕捉的異常，可以通過(guò)集成Zipkin服務(wù)界面上看到;
• 鏈路優(yōu)化: 對(duì)于調(diào)用比較頻繁的服務(wù)搂橙，可以針對(duì)這些服務(wù)實(shí)施一些優(yōu)化措施歉提。

PS：spring-cloud-sleth 2.0 中開(kāi)始 正式支持 Dubbo，思路的話則是通過(guò)Dubbo filter 擴(kuò)展機(jī)制区转。

小結(jié)

再講講為什么不引入Sleuth + ZipKin 這種解決方案呢苔巨？因?yàn)槲覀兿到y(tǒng)的調(diào)用鏈路并不復(fù)雜，一般只有一層的調(diào)用關(guān)系废离，所以并不希望增加第三方的組件侄泽，更傾向于使用簡(jiǎn)單的解決方案。

本篇文章到這里就結(jié)束了蜻韭。實(shí)現(xiàn)一個(gè)簡(jiǎn)單的微服務(wù)調(diào)用追蹤的日志方案并沒(méi)有太大的難度悼尾，重要的還是解決問(wèn)題的思路，并且觸類旁通肖方，去學(xué)習(xí)一些市面上的已存在的優(yōu)秀技術(shù)解決方案闺魏。

如果本文有幫助到你，希望能點(diǎn)個(gè)贊俯画，這是對(duì)我的最大動(dòng)力舷胜。