自实现分布式链路追踪方案&实践

悠悠 2023-09-24 21:47 122阅读 0赞

# 前言： #

排查问题是程序员的基本能力也是必须要会的，在开发环境，我们可以debug,但是一旦到了服务器上，就很难debug了，最有效的方式就是通过日志揪出bug，而一次请求的日志如果没有一个唯一的链路标识（我们下边称他为traceId）,单靠程序员人工分析的话，费时费力，尤其是请求量高频的接口，更是雪上加霜，排查问题效率大打折扣，作为程序员，低效的方式是忍不了的！！！ 本文我将用一次实战演练，来演示常用框架/中间件/多服务 之间如何传递traceId

**本文大概有如下内容：**

*  1.  链路追踪简述和自实现思路
 *  1.  单服务内如何实现链路id的输出
 *  1.  垮服务调用时，实现链路id传递的各种方式
    
     *  `( 包含http（openFeign,httpClient restTemplate）、rpc(motan、 dubbo)、mq（RocketMq）`)
 *  1.  异步调用时，如何解决log4j2自带的ThreadLocal丢失链路id问题
 *  1.  起4个服务，进行调用，观察链路追踪的效果

# 1、链路追踪实现简述 #

所谓链路追踪，就是为了 把整个请求链路从头到尾串起来，**不管调用链路有多深，多复杂，只要将一次链路完整无误的串联起来，就是合格的链路追踪功能**。

业界不乏`skywalking zipkin` 等等链路追踪方面牛逼的框架，**但是**我们为了更轻量更灵活可控同时也是抱着学习心态，所以自己来实现链路追踪。

首先想实现链路追踪，**有两点是核心**，实现了这两点，问题也就不大了

1.  **traceId 如何在`本地` (或者说`单服务内`) `传递`？**
2.  **在`分布式环境`中，traceId如何`跨服务/中间件 传递`？**

# 2、单体服务 的链路追踪 #

首先我们先讲下单服务内的链路传递

作为java开发，最常用的就是slf4j来实现打印日志的功能（但是slf4j并不没有实现逻辑，因为 slf4j整个的定义是一个日志门面，该包中并无具体的实现，实现都是在 比如：`logback log4j2`等等日志实现框架中）

`slf4j的门面`不仅给我们提供了打印日志的功能，还提供了 `org.slf4j.MDC` 类， 该类的作用大概如下：

> 映射诊断上下文（Mapped Diagnostic Context，简称MDC）是一种工具，用于区分不同来源的交错日志输出。当服务器几乎同时处理多个客户机时，日志输出通常是交错的。 **MDC是基于每个线程进行管理的** 。

上边这个官方解释，最重要的一句话就是 **MDC是基于每个线程进行管理的**

**上边这个太官方，说下我个人对MDC的理解：**

> 他是一个日志的扩展，`扩展的目的就是给 每个线程 输出的日志打上一个标记`（一个线程只有一个标记且不能重复一般使用uuid即可），这样我们在查看日志时候，就`可以根据这个标记来区分调用链路`了
> 
> **ps:** 当然了， 光往MDC中设置当前线程的链路id也是不行的你还得在log4j2.xml文件中，设置占位符，这样最终输出的日志才会带链路信息。如何设置会在 2.1节 有讲。

**从代码层面看下 MDC做了啥：**

1.  MDC类中通过一个 MDCAdapter实例
2.  调用MDCAdapter的put get remove clear等方法。
3.  而put get remove clear 具体的实现是不同厂商来做的 比如我常用的log4j2包中就实现了 MDCAdapter 接口，实现在 org.apache.logging.slf4j.Log4jMDCAdapter类中
4.  Log4jMDCAdapter类中使用了一个 ThreadContext来执行put get remove clear逻辑，
5.  而ThreadContext 中又是一个 ThreadContextMap ThreadContextMap是一个接口 ，有不同的实现
6.  其中默认的是 DefaultThreadContextMap 该类中维护了一个 ThreadLocal<Map<String, String>> localMap 类型的成员变量 其中map中的k,v 就是你调用MDC.put(k,v); 时传入的k v
7.  最终你调用MDC.put(k,v);时候传入的k和v会被放倒 localMap这个ThreadLocal中去。
8.  在你给某个线程设置了key,value后 ，log4j2在打印日志时候，将会去log4j2.xml文件中找 占位符等于 key的，然后用value把占位符替换，从而打印输出了value(也就是traceId)，**至此实现了单服务内的链路追踪。**

**把代码流程梳理下大概如下：**

MDC（类）
    	MDCAdapter（接口）
    		Log4jMDCAdapter(实现类之一)
    			ThreadContext（类）
    				ThreadContextMap（接口）
    					DefaultThreadContextMap
                                                    //(MDC的几个操作都是往这个里边存取数据)
    						ThreadLocal<Map<String, String>> localMap;
                                                    
    复制代码

## 2.1、如何使用MDC来输出（单服务内的）链路信息？ ##

1.  往MDC中设置key value
    
     *  ![format_png][]
2.  在log4j2.xml 中设置占位符（注意：占位符名称要和MDC中的key一致）
    
     *  ![format_png 1][]
3.  接着我们简单看下效果：（可以看到，每一个线程，都有一个唯一的链路id ）
    
     *  ![format_png 2][]

上边我们说过 MDC最终设置的key,value 是放到 `DefaultThreadContextMap`类中的 `ThreadLocal<Map<String, String>> localMap` 这个里边的，也就是说 里边的Map<String,String>是`某个线程`的`本地副本`（不懂线程本地副本的可以回顾下ThreadLocal的知识），有了这个知识基础，我们就不难理解为什么输出的日志是`每个线程都有唯一的traceId`了。

**举个例子来说就是：**

*  `线程t1` 往MDC中设置的 key,value ，当log4j2打印t1的日志时，会找到当前（t1）线程设置的value,来把 log4j2.xml 中的占位符替换
 *  `线程t2` 往MDC中设置 key,value ，当log4j2打印t2的日志时，会找到当前（t2）线程设置的value,来把 log4j2.xml 中的占位符替换

**ok,从上边可以了解到，单服务内通过slf4j提供的MDC功能，可以实现 某服务内 的链路追踪。**

**我们都知道，所谓微服务，都是由各个小的单服务组合起来的，通过上边的描述，我们知道单服务内如何打印链路了，那么微服务间不管怎么调用，只要保证在请求最开始（一般是网关）生成一个链路id，在后续的调用中将这个链路id一层层传递下去，整个完整的调用链路追踪也就实现了。在下边小节，我们就看看traceId是怎么垮服务传递的。**

--------------------

# 3、跨服务 的链路追踪实现简述 #

**垮服务间调用，本质上就是各个服务之间进行通信的过程**， 一般情况下，微服务间常用通信方式有如下几种：`（这里我们仅从应用层来看，如果从传输层看的话 1和2 都是tcp）`

1.  rpc
2.  http
3.  消息队列（mq）
4.  其他可能我不知道的

> 在日常开发中`我常用`的 :
> 
> **http** 框架有 `apache的 httpclient` ， `springcloud的 openfeign`, `spring包中的 resttemplate` ，`okhttp`（okhttp一般安卓用的比较多）。
> 
> **rpc** 框架的话一般是`dubbo` 、`motan` 其他的本人没怎么用过。
> 
> **mq** 的话我用过kafka rabbitmq rocketmq

下边，我搭建了四个微服务，分别是

> **网关服务 study-gateway**，
> 
> **微服务消费服务 study-consumer**
> 
> **后台管理服务 study-admin**
> 
> **订单服务 study-order**

在这里我的 **调用链路** 大概如下图所示：

![format_png 3][]

如上图所示的链路，该次请求会经过 `网关`，`openFeign`，`异步调用`，`httpClient`调用，`mq` 这几个组件，而如何在这几个组件 `调用前传递traceId 和 调用后设置traceId` 成为垮服务进行链路追踪的关键。 ps: dubbo和motan的我们就不演示了，会直接给出传递方案。

铺垫了那么多，我们下边直接了当点不再啰嗦！

## 3.1、在请求最前边（study-gateway）添加过滤器 ##

在网关过滤器中生成并设置traceId到MDC（此刻网关服务的日志中将会打印traceId） ,同时通过header传递到下游服务。

![format_png 4][]

简单看下网关配置：

## 3.2、在路由目标 服务(study-consumer)中添加过滤器(为了从请求头获取链路id) ##

![format_png 5][]

## 3.3、在study-consumer服务添加feign拦截器（因为consumer要通过feign调用study-admin服务） ##

![format_png 6][]

## 3.4、在study-admin中添加过滤器（为了从请求头获取链路id） ##

![format_png 7][]

## 3.5、在httpClient工具中添加拦截器(对外调用时候往header设置链路id) ##

![format_png 8][]

## 3.6、在resttemplate中添加拦截器(对外调用时候往header设置链路id) ##

![format_png 9][]

注册拦截器到RestTemplate实例:

## 3.7、在RocketMq`发送前`和`消费前`添加钩子 ##

发送前添加钩子：

![format_png 10][]

消费前添加钩子：

分别往生产和消费实例对象中设置钩子:

![format_png 11][]

## 3.8、用ttl解决异步调用存在的问题（在这里我们也一并说了不再啰嗦） ##

上边我们也说了，MDC底层 `DefaultThreadContextMap` 是用 ThreadLocal 来保存的链路信息，而ThreadLocal是同一个线程，才会有相同的副本数据，而当我们在项目中使用线程池时候，主线程和子线程肯定是不一样的，那么这种情况下就得考虑如何将主线程的值传递给子线程，让子线程也能记录traceId,从而保证 链路不会断！

值的一说的是jdk也想到了这个问题，提供了一个 `InheritableThreadLocal`类，但是这个类并不适用于链路追踪场景，因为在`异步调用`场景下，`是要保证每一次请求，都要将主线程的traceId传递给子线程`，而 `InheritableThreadLocal只能是第一次时候传递,或者说他不是每次都传递给子线程更贴切`，下边看下官方的描述：

**InheritableThreadLocal存在的问题：官方原话: 使用InheritableThreadLocal时(ThreadContext 可能并不总是自动传递给工作线程)**

由于线程池的复用机制，所以第n次请求时，线程池中线程所打印出的链路id,还是上次或者是上n次的链路id（我试验了确实如此）,而我们真实希望是，**线程池中线程打印的链路id保持和当前主线程中的链路id一致**，换句话说: 我们需要的是 **任务提交给线程池时**的链路id传递到 **任务执行时**。

既然InheritableThreadLocal不满足需求，那么怎么办呢？看下边：

在log4j2中，他底层是通过spi机制提供了 对 `ThreadContextMap`接口的`扩展能力` ，不了解的可以去看看官网，而正好阿里开源了一个这个小框架 [ttl][] 和 [ttl-thread-context-map][] ，ttl-thread-context-map 可以解决线程间的传递丢失问题（他内部也是使用的`TransmittableThreadLocal也就是ttl`来存储MDC 的key和value）。ttl-thread-context-map 依赖java的spi机制，依靠spi机制，让log4j2 在启动加载时，用log4j2.component.properties中 `log4j2.threadContextMap`这个key 对应的 value作为`ThreadContextMap` 接口的实现（也就是替换掉`DefaultThreadContextMap这个默认实现`）,从而实现了线程间传递的功能。对ttl和ttl-thread-context-map不熟悉的可以跳的github 讲的很详细很清楚。

**TtlThreadContextMap内部使用TransmittableThreadLocal来存储MDC的key,value**

![format_png 12][]

**spi配置：**

而我们使用阿里这个工具也很简单首先maven引入(注意版本 不清楚的去maven库看看)

<dependency>
       <groupId>com.alibaba</groupId>
       <artifactId>transmittable-thread-local</artifactId>
       <version>2.14.2</version>
    </dependency>
    <dependency>
       <groupId>com.alibaba</groupId>
       <artifactId>log4j2-ttl-thread-context-map</artifactId>
       <exclusions>
          <exclusion>
             <groupId>org.apache.logging.log4j</groupId>
             <artifactId>log4j-api</artifactId>
          </exclusion>
       </exclusions>
       <version>1.4.0</version>
       <scope>runtime</scope>
    </dependency>
    复制代码

在引入这个后，我什么也没配，如果我使用jdk的 `ThreadPoolExecutor` 或者spring的 `ThreadPoolTaskExecutor`，都是可以实现链路传递的，但是我使用 `CompletableFuture`的话，第一次请求的链路是对的，当第二次请求时候，CompletableFuture线程池中的打印链路信息还是第一次的，这个问题github上有说明，作者让使用javaagent来解决，果然在我配置javaagent后，CompletableFuture 的链路信息每次都是正确的。

> 在idea 的 VM options 中配置：
> 
> \-javaagent:/Users/hzz/.m2/repository/com/alibaba/transmittable-thread-local/2.14.2/transmittable-thread-local-2.14.2.jar

即可解决 CompletableFuture的链路id传递问题（这里我们最好是agent这样对代码无侵入，如果你使用TtlRunable修饰Runable的话 对代码侵入比较多，维护起来也比较麻烦）

![format_png 13][]

# 4、跨服务+异步 链路追踪效果演示 #

最后我们将四个服务启动，看下整体效果：

postman调用：

![format_png 14][]

**study-gateway**

![format_png 15][]

**study-consumer**

![format_png 16][]

**study-admin**

![format_png 17][]

tcpdump抓包看看第三方的请求头中是否含有了链路id:

**study-order**

![format_png 18][]

上边几张截图可以看到下边这个调用链 通过链路id 可以完美的串起来了！

![format_png 19][]

## **至此，垮服务进行链路追踪完成！** ##

最后我将TraceIdUtil代码粘出来。

package com.xzll.common.util;
    
    import com.xzll.common.constant.StudyConstant;
    import jodd.util.StringUtil;
    import org.apache.commons.lang3.StringUtils;
    import org.slf4j.MDC;
    
    import javax.servlet.http.HttpServletRequest;
    import java.util.UUID;
    
    /**
     * @Author: hzz
     * @Date: 2023/2/26 15:19:36
     * @Description:
     */
    public class TraceIdUtil {
    
       public static final String REGEX = "-";
    
       /**
        * 从header和参数中获取traceId
        * 从网关传入数据
        *
        * @param request 　HttpServletRequest
        * @return traceId
        */
       public static String getTraceIdByRequest(HttpServletRequest request) {
          String traceId = request.getParameter(StudyConstant.TraceConstant.TRACE_ID);
          if (StringUtils.isBlank(traceId)) {
             traceId = request.getHeader(StudyConstant.TraceConstant.TRACE_ID);
          }
          return traceId;
       }
    
       public static String getTraceIdByLocal() {
          return MDC.get(StudyConstant.TraceConstant.TRACE_ID);
       }
    
       /**
        * 传递traceId至MDC
        *
        * @param traceId 　链路id
        */
       public static void setTraceId(String traceId) {
          if (StringUtil.isNotBlank(traceId)) {
             MDC.put(StudyConstant.TraceConstant.TRACE_ID, traceId);
          }
       }
    
       /**
        * 构建traceId
        * @return
        */
       public static String buildTraceId() {
          return UUID.randomUUID().toString().replaceAll(REGEX, StringUtils.EMPTY);
       }
    
       /**
        * 清理traceId
        */
       public static void cleanTraceId() {
          MDC.clear();
       }
    }
    
    复制代码

# 5、结尾 #

由于我的项目中没有使用motan和dubbo所以无法演示rpc调用，但是我接触的项目有，这里不粘完整代码了 ，直接给出答案，在motan中也是支持配置过滤器的 ，在调用前，通过过滤器往request的attachment中设置traceId来将traceId传递给服务提供者，在服务提供者中也可以添加过滤器，此时从attachment属性中取出traceId通过MDC.put(key,value)来将traceId设置进本服务。达到链路传递的效果。 同理dubbo框架也是类似做法。

ps:

1.  由于时间原因，我的四个服务中，有多处冗余代码，比如过滤器，这些类似公共的都可以抽出来搞一个starter或者是导入bean等等方式，来减少重复代码。
2.  由于本文重点讲述使用方面的东西，原理方面的不做过多解散，关于ttl和 `log4j2-ttl-thread-context-map` ，可以看看github的资料，已经讲的超级细了。另外如果像知道更多细节，需要从slf4j和log4j2的源码入手，相信会有更多的收获。你会发现每天使用的slf4j log4j2 里边居然这么多值的学习的地方！！！

[format_png]: https://img-blog.csdnimg.cn/img_convert/1b17487d4e7203348097e904084c53fa.webp?x-oss-process=image/format,png
[format_png 1]: https://img-blog.csdnimg.cn/img_convert/0cb44394dd80ec601700b6ef7326e744.webp?x-oss-process=image/format,png
[format_png 2]: https://img-blog.csdnimg.cn/img_convert/aa5c9f72c2816dafc73da6471d16fbc4.webp?x-oss-process=image/format,png
[format_png 3]: https://img-blog.csdnimg.cn/img_convert/f5793904f26e6f4d91e4f91be66fe822.webp?x-oss-process=image/format,png
[format_png 4]: https://img-blog.csdnimg.cn/img_convert/0e24fef1b8c41fc31524851174a55068.webp?x-oss-process=image/format,png
[format_png 5]: https://img-blog.csdnimg.cn/img_convert/3fca4b01fd6e9b4be1e3361cfe99b4e9.webp?x-oss-process=image/format,png
[format_png 6]: https://img-blog.csdnimg.cn/img_convert/e3e9754ef6d4a094fe5a92b13fbb2bc5.webp?x-oss-process=image/format,png
[format_png 7]: https://img-blog.csdnimg.cn/img_convert/77c807a2d9fd5b6a61242d0916b85489.webp?x-oss-process=image/format,png
[format_png 8]: https://img-blog.csdnimg.cn/img_convert/c63563dc060890b7e19ac6e3cfb70e0c.webp?x-oss-process=image/format,png
[format_png 9]: https://img-blog.csdnimg.cn/img_convert/adbfaed119e6b8bec31c7924050b56f3.webp?x-oss-process=image/format,png
[format_png 10]: https://img-blog.csdnimg.cn/img_convert/76aa27bb89fac0a3bc8c84653db4a638.webp?x-oss-process=image/format,png
[format_png 11]: https://img-blog.csdnimg.cn/img_convert/fa16b163eef445fd77de62b9f4095958.webp?x-oss-process=image/format,png
[ttl]: https://link.juejin.cn?target=https%3A%2F%2Fgithub.com%2Falibaba%2Ftransmittable-thread-local
[ttl-thread-context-map]: https://link.juejin.cn?target=https%3A%2F%2Fgithub.com%2Foldratlee%2Flog4j2-ttl-thread-context-map
[format_png 12]: https://img-blog.csdnimg.cn/img_convert/04da0375820685e459bfed42d1909b2b.webp?x-oss-process=image/format,png
[format_png 13]: https://img-blog.csdnimg.cn/img_convert/f805c616aef08ce8b9b94f3b9859306a.webp?x-oss-process=image/format,png
[format_png 14]: https://img-blog.csdnimg.cn/img_convert/0695d6c2ddc0a873716100c25288c63c.webp?x-oss-process=image/format,png
[format_png 15]: https://img-blog.csdnimg.cn/img_convert/a3ad6a4f24b214851b3e9816ee4b7c7c.webp?x-oss-process=image/format,png
[format_png 16]: https://img-blog.csdnimg.cn/img_convert/6b4e35d781a62d74aae20ed53c60ceb8.webp?x-oss-process=image/format,png
[format_png 17]: https://img-blog.csdnimg.cn/img_convert/6266dd74fad29aed80b32f4b4e5540a5.webp?x-oss-process=image/format,png
[format_png 18]: https://img-blog.csdnimg.cn/img_convert/5c630c5cac71a42e68266bd91db67bc8.webp?x-oss-process=image/format,png
[format_png 19]: https://img-blog.csdnimg.cn/img_convert/08ebd998c6254d8817a2348442508244.webp?x-oss-process=image/format,png