小白都能看得懂的服务调用链路追踪设计与实现

目  录：

1. 服务调用链路概念

2. 服务调用日志追踪设计

    2.1 拦截器

    2.2 logback 日志

3. 链路追踪之拦截器实现

    3.1 环境准备

    3.2 工程搭建

    3.3 日志追踪实现

    3.4 测试

4. 小结

一、服务调用链路的概念

系统服务调用链路是指从用户或是机器发起服务请求到结束，按顺序记录整个请求链路的相关数据，以备后续查询分析、定位系统 bug 或性能优化所用。

目前市面上，几乎所有服务调用链路的实现，理论基础都是基于 Google Dapper 的那篇论文，其中最重要的概念就是 traceId 和 spanId。

• traceId 记录整个服务链路的 ID，由首次请求方创建，服务链路中唯一。

• spanId 记录当前服务块的 ID，由当前服务方创建。

• parentId 记录上一个请求服务的 spanId。

二、日志追踪设计方案

设计思路很简单：就是使用自定义拦截器 + 日志 自定义格式化（logback）实现即可。

• 拦截器的作用：拦截器请求，当用户或机器向服务器发起请求时，服务器应用程序进行拦截，在请求真正的接口前获取请求头（Headers）中传递的参数（trace-id），并存储在 ThreadLocal<T> 中，作为请求的线程共享局部变量。在请求结束时需要手动调用 remove() 方法移除变量副本，防止内存泄漏。

快速回顾 ThreadLocal 知识点（知道的请直接往下划，想了解更深建议直接看源码），如下：

ThreadLocal 由来简介：在 JDK 1.2 的版本中就提供 java.lang.ThreadLocal，ThreadLocal 为解决多线程程序的并发问题提供了一种新的思路。ThreadLocal 并不是一个 Thread，而是 Thread 的局部变量。在 JDK 5.0 中，ThreadLocal 开始支持泛型，使其功能更加灵活强大。
ThreadLocal<T> 类中提供了几个重要方法简介：# 获取当前线程中保存的变量副本1.public T get() { }# 设置当前线程中变量的副本2.public void set(T value) { }# 移除当前线程中变量的副本3.public void remove() { }# 初始化当前线程中变量的副本4.protected T initialValue(){ }
ThreadLocal 应用场景简介：在 Java 的多线程编程中，为保证多个线程对共享变量的安全访问，通常会使用 synchronized 来保证同一时刻只有一个线程对共享变量进行操作。这种情况下可以将类变量放到 ThreadLocal 类型的对象中，使变量在每个线程中都有独立拷贝，不会出现一个线程读取变量时而被另一个线程修改的现象。最常见的 ThreadLocal 使用场景为用来解决数据库连接、Session 管理等。

• 借助 logback 日志实现日志打印（可以通过 ELK 日志框架记录分析展示等），支持自定义日志参数，继承 ch.qos.logback.classic.pattern.ClassicConverter.class 实现自定义日志格式化。

三、链路追踪之拦截器实现

1. 开发环境准备

• MacOS + IDEA 2019.3 + Maven 3.3.9 + SpringBoot 2.2.6

2. 工程初始化步骤如下：

2.1 通过这个网址（https://start.spring.io/）构建 SpringBoot 项目，如下所示：

2.2 通过 IDEA 2019.3 构建 SpringBoot 项目

步骤如下所示：

工程目录如上图所示，到这里我们的 SpringBoot 工程就算搭建好了，下面开始新建相应的包，配置类的包名 config、拦截器的包名 interceptor、控制器的包名 controller，结果如下：

2.3  在 com.smart4j.core.logtrack.interceptor 包下新建日志追踪拦截器类 

LogTrackController.class，代码截图如下： 

代码清单如下（便于测试）：

package com.smart4j.core.logtrack.interceptor;
import org.springframework.stereotype.Component;import org.springframework.web.servlet.HandlerInterceptor;
import javax.servlet.http.HttpServletRequest;import javax.servlet.http.HttpServletResponse;import java.util.Optional;import java.util.UUID;
/** * @Description: 日志追踪拦截器* @Param:  * @return:  * @Author: Mr.Zhang * @Date: 2020/4/14*/ @Componentpublic class LogTrackInterceptor implements HandlerInterceptor {  /**   * 存储 traceId   */  private static final ThreadLocal<String> TRACE_ID_THREAD_LOCAL = new ThreadLocal<>();
  @Override  public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {    /**     * 获取请求头header中传递的trace-id，若没有，则UUID代替     */    String traceId = Optional.ofNullable(request.getHeader("trace-id")).orElse(UUID.randomUUID().toString().replaceAll("-",""));    // 请求前设置    TRACE_ID_THREAD_LOCAL.set(traceId);    return true;  }
  @Override  public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {    // 移除，防止内存泄漏    TRACE_ID_THREAD_LOCAL.remove();  }
  public static String getTraceId() {    return TRACE_ID_THREAD_LOCAL.get();  }
  public static void setTraceId(String traceId){    TRACE_ID_THREAD_LOCAL.set(traceId);  }
}

2.4  在 com.smart4j.core.logtrack.config 包下新建自定义拦截器注册配置类 

CustomInterceptorConfig.class，代码截图如下：

代码清单如下（便于测试）：

package com.smart4j.core.logtrack.config;
import com.smart4j.core.logtrack.interceptor.LogTrackInterceptor;import org.springframework.beans.factory.annotation.Autowired;import org.springframework.context.annotation.Configuration;import org.springframework.web.servlet.config.annotation.InterceptorRegistry;import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;

/** * @Description: 注册自定义拦截器* @Param:  * @return:  * @Author: Mr.Zhang * @Date: 2020/4/14*/ @Configurationpublic class CustomInterceptorConfig implements WebMvcConfigurer {
  @Autowired  private LogTrackInterceptor logTrackInterceptor;
  @Override  public void addInterceptors(InterceptorRegistry registry) {    registry.addInterceptor(logTrackInterceptor);  }}

2.5 在 com.smart4j.core.logtrack.config 包下新建自定义logback日志格式化类 

TraceIdPatternConverter.class，代码截图如下：

代码清单如下（便于测试）：

package com.smart4j.core.logtrack.config;
import ch.qos.logback.classic.pattern.ClassicConverter;import ch.qos.logback.classic.spi.ILoggingEvent;import com.smart4j.core.logtrack.interceptor.LogTrackInterceptor;import org.springframework.util.StringUtils;

/*** @Description:  自定义日志格式化* @Param:* @return:* @Author: Mr.Zhang* @Date: 2020/4/14*/public class TraceIdPatternConverter extends ClassicConverter {  @Override  public String convert(ILoggingEvent iLoggingEvent) {    String traceId = LogTrackInterceptor.getTraceId();    return StringUtils.isEmpty(traceId) ? "traceId" : traceId;  }}

2.6 在 com.smart4j.core.logtrack.controller 包下新建控制器类 

LogTrackController.class，代码截图如下：

代码清单如下（便于测试）：

package com.smart4j.core.logtrack.controller;
import lombok.extern.slf4j.Slf4j;import org.springframework.web.bind.annotation.GetMapping;import org.springframework.web.bind.annotation.RequestMapping;import org.springframework.web.bind.annotation.RestController;
/*** @Description:  测试日志追踪* @Param:* @return:* @Author: Mr.Zhang* @Date: 2020/4/14*/@Slf4j@RestController@RequestMapping("/test")public class LogTrackController {
  @GetMapping("/log")  public String logTrack(){    log.info("-----> 测试 info <-----");    log.warn("-----> 测试 warn <-----");    log.error("-----> 测试 error <-----");    return null;  }
}

‍

2.7 在项目的 resources 资源目录下新建 logback 日志配置文件（logback-spring.xml ），内容如下（主要有4个部分，见框选标识）：

<?xml version="1.0" encoding="UTF-8"?><configuration>  <!-- 获取 traceId 配置类-->  <conversionRule conversionWord="traceId" converterClass="com.smart4j.core.logtrack.config.TraceIdPatternConverter" />  <!-- 自定义 logback 日志格式-->  <property name="CUSTOM_LOG_PATTERN"            value="[[[%date{yyyy-MM-dd HH:mm:ss} | %-5level | %traceId | %thread | %file:%line | %logger : %.1000m]]]%n" />
  <!-- 控制台输出 -->  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">    <encoder>        <pattern>${CUSTOM_LOG_PATTERN}</pattern>    </encoder>  </appender>
  <root level="INFO">    <!-- 控制台打印 -->    <appender-ref ref="STDOUT"/>  </root></configuration>

‍

2.8 最终的项目结构呈现如下图所示：

2.9 启动项目

通过 SpringBoot 启动类 LogTrackApplication.class 启动 log-track 工程，启动成功如下图所示：

2.10 测试

通过 Postman 模拟请求 http://localhost:8080/test/log（请求头中不添加 trace-id 参数），控制台输出日志结果如下：

[[[2020-04-14 19:53:41 | INFO  | 6ee9257270474ce38826a8b842adb06f | http-nio-8080-exec-1 | LogTrackController.java:22 | com.smart4j.core.logtrack.controller.LogTrackController : -----> 测试 info <-----]]][[[2020-04-14 19:53:41 | WARN  | 6ee9257270474ce38826a8b842adb06f | http-nio-8080-exec-1 | LogTrackController.java:23 | com.smart4j.core.logtrack.controller.LogTrackController : -----> 测试 warn <-----]]][[[2020-04-14 19:53:41 | ERROR | 6ee9257270474ce38826a8b842adb06f | http-nio-8080-exec-1 | LogTrackController.java:24 | com.smart4j.core.logtrack.controller.LogTrackController : -----> 测试 error <-----]]]

请求增加请求头设置（trace-id = 1234567890），请求结果如下所示：

四、小  结

基于 SpringBoot 2.2.6，使用拦截器 + logback 日志实现一个简单的服务内日志追踪设计方案。

留个思考题吧：如果接口内部存在多线程（线程池）异步调用，这时用上面提供的设计方案记录的TraceId 还会有效吗？如果不能实现真实的调用链跟踪记录，那么又该如何实现呢？小伙伴们动脑想一想，欢迎在留言区发表你的想法，下次我会说说我的思路和实现，敬请期待！

加油

# 精彩推荐 #

  事务看完这篇你只能算入门

  微服务架构中你必须了解的 CAP 原理

 趣谈微服务之点-线-面关系

  [三步法] 可视化分析定位线上 JVM 问题

  从 Java 代码如何运行聊到 JVM 和对象的创建-分配-定位-布局-垃圾回收

  记一次生产频繁出现 Full GC 的 GC日志图文详解

 "在看"吗，快分享和收藏吧