Spring Cloud Sleuth是Spring Cloud提供的分布式跟踪解决方案，它借用了Google的Dapper组件的术语，并且兼容Twitter的Zipkin。
Spring Cloud Sleuth官网：https://docs.spring.io/spring-cloud-sleuth/docs/2.2.8.RELEASE/reference/html/#terminology
zipkin官网：https://zipkin.io/
1. 分布式场景链路跟踪问题
在复杂的微服务架构系统中，几乎每一个前端请求都会形成一条复杂的分布式服务调用链路， 在每条链路中任何一个依赖服务出现延迟过高或错误的时候都有可能引起请求最后的失败。
问题：
- 怎么定位出问题的服务和异常原因？逐个服务去查看日志？
- 如何去分析每个服务节点的耗时？
Spring Cloud Sleuth 具备了以下特性：
- 通过sleuth可以很清楚的看出一个请求都经过了哪些服务；
- Sleuth+zipkin 在 web UI 可以对程序的异常进行可视化展示；
- 通过sleuth中Span的Annotation事件可以很方便的看出每个采样请求的耗时，分析出哪些服务调用比较耗时。
2. Sleuth简介
2.1 Sleuth 跟踪原理
链路跟踪理论上有两个个关键点：
- 标识一次分布式请求的链路跟踪，Sleuth框架为该请求创建一个唯一的跟踪标识（ Trace ID ），同时在每个 Span（一个Span对应一次服务调用）中保存该 Trace ID ，直到返回请求为止，通过该 Trace ID ，就能将不同服务调用的日志串联起来。
- 统计服务处理的耗时，每次服务调用都对应一个Span，Span包括一个64位的唯一ID，一个64位trace id，Annotation事件列表等信息，每个Annotation事件都记录该事件的开始时间，通过事件之间的时间差，可以得出各个处理步骤的耗时。
2.2 术语
-
Trace：Trace 结构表示对一次请求的跟踪，它是由一组有相同Trace ID的Span组成的一个树状结构。为了实现请求跟踪，
-
Span：它代表了一个基础的工作单元，例如服务调用。Span包括一个64位的唯一ID，一个64位trace码，描述信息，时间戳事件，key-value 注解(tags)，span处理者的ID（通常为IP）。
root span：开始一个 Trace 的初始Span，root span的ID的值等于trace ID。
- Annotation：它用于记录一段时间内的事件。内部使用的最重要的注释是：
- CS（Client Sent 客户端发送）：客户端发送一个请求，表示span的开始；
- SR（Server Received 服务端接收）：服务端接收请求并开始处理请求。(SR - CS)等于请求网络的延迟；
- SS（Server Sent 服务端发送）：服务端处理请求完成，开始返回结果给服务端。(SR - SS)表示服务端处理请求的时间；
- CR（Client Received 客户端接收）：客户端完成接收返回的结果，此时span结束。(CR - CS)表示客户端从服务器接收响应整个请求所消耗的时间
下面看看Sleuth官网上的图形化例子：
如果一个服务请求的调用链路如下：
则该请求链路的Span和Trace在一个系统中使用Zipkin注解的过程图形化如下：
每种颜色都表示一个Span，从A到G共有七个Span，同一个请求跟踪中，所有的Span都具有相同的Trace ID。
比如下面Span，Trace Id为X，Span Id是D，发生了Client Sent事件。
Trace Id = X
Span Id = D
Client Sent
下图显示了各个span的父子关系：
2.3 如何在请求间传递跟踪的上下文信息
当一个请求被跟踪时，在传播中会添加一下请求头header，用来传播一下id，比如spanId，traceId等，但是不会传输详细信息，比如操作名称。
在请求头信息中多了 4 个属性：
- x-b3-spanid：一个工作单元(rpc 调用)的唯一标识。
- x-b3-parentspanid：当前工作单元的上一个工作单元，Root Span(请求链路的第一个工作单元)的值为空。
- x-b3-traceid：一条请求链条(trace) 的唯一标识。
- x-b3-sampled：是否被抽样被导出(采样)的标志，1 为需要被导出，0 为不需要被导出。
2.4 sleuth 采样配置
采样也就是将跟踪数据发送到zipkin。无论采样率如何，Trace ID 都会出现在日志中。
sleuth 采样的比例越大，机器的负载就越高，生产环境需要根据机器性能来去配置采样比例。默认是 spring.sleuth.sampler.rate = 10，每秒 10 次跟踪。
方式一：
配置文件配置，如 application.yml:
spring:
sleuth:
sampler:
# 跟踪信息收集采样比例，默认 0.1，为 1 是即 100%，收集所有，默认0.1(即10%)
probability: 1
# 每秒速率，即每秒最多能跟踪的请求，rate 优先，默认是10
rate: 20
方式二：
java bean 配置：Sampler.ALWAYS_SAMPLE表示全部采样；Sampler.NEVER_SAMPLE表示都不采样；
/**
* 通过java bean的方式配置 seluth 采样比例
*
* @return
*/
@Bean
public Sampler defaultSampler() {
// Sampler.ALWAYS_SAMPLE表示全部采样；
// Sampler.NEVER_SAMPLE表示都不采样；
return Sampler.ALWAYS_SAMPLE;
}
3. zipkin简介
Zipkin是Twitter的一个开源项目，我们可以使用它来收集各个服务器上请求链路的跟踪数据，并通过它提供的API接口来辅助查询跟踪数据，或者通过UI组件可视化地展示服务调用链路中各个服务节点的是否异常和处理耗时。
zipkin的处理流程图：
- Reporter: 应用程序中向zipkin发送跟踪数据的组件。
- Transport: Reporter发送数据给zipkin收集器的传输方式，三种主要传输方式：HTTP、Kafka 和 Scribe
- Storage：zipkin将跟踪数据保存至Storage中。
- API 将查询存储以向UI提供数据。
zipkin的4个组件：
- Collector（收集器组件）：主要负责收集外部系统跟踪信息，跟踪数据到达Zipkin收集器守护进程后，将对其进行验证、存储和索引，以便Zipkin收集器进行查找。
- Storage（存储组件）：主要负责收到的跟踪信息的存储，默认为存储在内存中，同时支持存储到Mysql、Cassandra以及ElasticSearch。
- API（Query）： 负责查询Storage中存储的数据，提供简单的JSON API获取数据，这个API主要提供给web UI使用。
- Web UI（展示组件）：提供简单的web界面，方便进行跟踪信息的查看以及查询，同时进行相关的分析。
示例时序图：
用户的应用发起Http Get（User Request）请求（请求路径/trace），经过spring cloud Sleuth的Trace框架（Trace Instrumentation）拦截，并依次经过如下步骤，最后记录Trace信息到Zipkin中：
- 记录tags信息；
- 将当前调用链的Trace信息记录到Http Headers中；
- 记录当前调用的时间戳（timestamp）；
- 发送http请求，并携带Trace相关的Header，如: X-B3-TraceId: aa，X-B3-SpanId: 6b；
- 调用结束后，记录当次调用所花的时间（duration）；
将步骤1-5，汇总成一个Span（最小的Trace单元），上报该Span信息给Zipkin Collector。
┌─────────────┐ ┌───────────────────────┐ ┌─────────────┐ ┌──────────────────┐
│ User Code │ │ Trace Instrumentation │ │ Http Client │ │ Zipkin Collector │
└─────────────┘ └───────────────────────┘ └─────────────┘ └──────────────────┘
│ │ │ │
┌─────────┐
│ ──┤GET /foo ├─▶ │ ────┐ │ │
└─────────┘ │ record tags
│ │ ◀───┘ │ │
────┐
│ │ │ add trace headers │ │
◀───┘
│ │ ────┐ │ │
│ record timestamp
│ │ ◀───┘ │ │
┌─────────────────┐
│ │ ──┤GET /foo ├─▶ │ │
│X-B3-TraceId: aa │ ────┐
│ │ │X-B3-SpanId: 6b │ │ │ │
└─────────────────┘ │ invoke
│ │ │ │ request │
│
│ │ │ │ │
┌────────┐ ◀───┘
│ │ ◀─────┤200 OK ├─────── │ │
────┐ └────────┘
│ │ │ record duration │ │
┌────────┐ ◀───┘
│ ◀──┤200 OK ├── │ │ │
└────────┘ ┌────────────────────────────────┐
│ │ ──┤ asynchronously report span ├────▶ │
│ │
│{ │
│ "traceId": "aa", │
│ "id": "6b", │
│ "name": "get", │
│ "timestamp": 1483945573944000,│
│ "duration": 386000, │
│ "annotations": [ │
│--snip-- │
└────────────────────────────────┘
3. 整合Spring Cloud Sleuth+zipkin
3.1 准备 zipkin 服务jar包
下载链接：search.maven.org/remote_content?g=io.zipkin&a=zipkin-server&v=LATEST&c=exec
我下载的是目前最新版本 zipkin-server-2.23.2-exec.jar，接着使用 java -jar zipkin-server-2.23.2-exec.jar 启动 zipkin 服务。
3.2 准备服务
本篇文章还将继续使用 《006-SpringCLoud》 文集中的工程 006SpringCloud。
目前工程中各个模块的描述如下：
| 工程/模块 | 端口 | 描述 |
|---|---|---|
| 006SpringCloud | 无 | 父工程，管理依赖版本依赖， springboot-2.3.3.RELEASE 和 spring-cloud-Hoxton.SR8 |
| common-api | 无 | 存放实体 |
| consumer-order8001 | 8001 | 服务消费者，集成了eureka-client 和 hystrix 组件， 演示服务发现和Hystrix降级熔断 |
| consumer-openFeign-order8002 | 8002 | 服务消费者，集成了eureka-client 和 openFeign组件， 演示服务发现和openFeign组件的使用 |
| consumer-zk-user8101 | 8101 | 服务消费者，集成了zookeeper-discovery 组件， 演示SpringCloud zookeeper的服务注册和发现 |
| eureka-server-7001 eureka-server-7002 |
7001、7002 | eureka注册中心 |
| gateway-6001 | 6001 | SpringCloud 网关，集成了 gateway 和 eureka-client 组件， 演示SpringCloud 网关的使用 |
| provider-payment9001 provider-payment9002 |
9001、9002 | 服务提供者，集成了 eureka-client 组件， 演示SpringCloud Eureka的服务注册和发现 |
| provider-zk-wechat9101 provider-zk-wechat9102 |
9101、9102 | 服务提供者，集成了 zookeeper-discovery 组件， 演示SpringCloud zookeeper的服务注册和发现 |
在本文中，我们会用到 gateway-6001 、 consumer-order8001、provider-payment9001、 eureka-server-7001 和 eureka-server-7002 集群。
在 gateway-6001 、 consumer-order8001、provider-payment9001 三个模块中加入 sleuth + zipkin 的依赖
<!-- sleuth + zipkin的依赖-->
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-zipkin</artifactId>
</dependency>
如下图所示，spring-cloud-starter-zipkin 依赖已经包含了 sleuth + zipkin 的依赖。
接着在三个模块的 application.yml 中加入 sleuth采样配置 和 zipkin 服务地址配置
spring:
zipkin:
# 配置zipkin的服务地址
base-url: http://localhost:9411/
sleuth:
sampler:
# 跟踪信息收集采样比例，默认 0.1，为 1 是即 100%，收集所有，默认0.1(即10%)
probability: 1
# 每秒速率，即每秒最多能跟踪的请求，rate 优先，默认是10
rate: 20
SpringCloud 网关 gateway-6001中已经开启根据 serviceId 转发：spring.cloud.gateway.discovery.locator.enabled=true
SpringCloud 网关 gateway-6001 启用了一个自定义的全局过滤器，这个全局过滤器只是为了演示日志打印。
@Component
public class LogGlobalFilter implements GlobalFilter, Ordered {
Logger logger = LoggerFactory.getLogger(this.getClass());
@Override
public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
ServerHttpRequest request = exchange.getRequest();
// 打印请求uri
logger.info("全局过滤器LogGlobeFilter开始：" + request.getURI().getPath());
Mono<Void> mono = chain.filter(exchange);
logger.info("全局过滤器LogGlobeFilter结束：" + request.getURI().getPath());
return mono;
}
@Override
public int getOrder() {
// order: 加载顺序，数值越小，优先级越高
return 0;
}
}
服务提供者 provider-payment9001 提供了下面的接口：
@RestController
@RequestMapping("/payment")
public class PaymentController {
private Logger logger = LoggerFactory.getLogger(PaymentController.class);
@Value("${server.port}")
private String serverPort;
@GetMapping("/getPayment/{id}")
public CommonResult<Payment> getPayment(@PathVariable("id") String id) {
logger.info("orderService getPayment开始，id="+id);
CommonResult result = this.restTemplate.getForObject(PAYMENT_URL + "/payment/get/" + id, CommonResult.class);
logger.info("orderService getPayment结束");
return result;
}
/**
* 服务提供者请求异常，级联故障
*
* @return
*/
@GetMapping(value = "/excep")
public CommonResult<Payment> excep() {
logger.info("orderService excep开始");
CommonResult result = this.restTemplate.getForObject(PAYMENT_URL + "/payment/excep", CommonResult.class);
logger.info("orderService excep结束");
return result;
}
...
}
``
服务消费者 consumer-order8001 提供接口 "/order/getPayment/{id}" 和 "/order/excep" 调用服务提供者 provider-payment9001 的接口。
```java
@RestController
@RequestMapping("/order")
@DefaultProperties(defaultFallback = "defaultFallbackMethod")//配置类级别默认的降级处理方法
public class OrderController {
private Logger logger = LoggerFactory.getLogger(OrderController.class);
public static final String PAYMENT_URL = "http://PAYMENTSERVICE";
@Autowired
private RestTemplate restTemplate;
@Autowired
HttpServletRequest request;
@GetMapping("/getPayment/{id}")
public CommonResult<Payment> getPayment(@PathVariable("id") String id) {
logger.info("orderService getPayment开始，id=" + id);
//打印 请求头，验证sleuth在请求头中传播跟踪信息
Enumeration<String> enu = request.getHeaderNames();
while (enu.hasMoreElements()) {
String name = enu.nextElement();
if (name.startsWith("x-b3-"))
logger.info("orderService getPayment request headers，name=" + name + " ------ value=" + request.getHeader(name));
}
CommonResult result = this.restTemplate.getForObject(PAYMENT_URL + "/payment/get/" + id, CommonResult.class);
logger.info("orderService getPayment结束，id=" + id);
return result;
}
/**
* 服务提供者请求异常，级联故障
*
* @return
*/
@GetMapping(value = "/excep")
public CommonResult<Payment> excep() {
logger.info("orderService excep开始");
CommonResult result = this.restTemplate.getForObject(PAYMENT_URL + "/payment/excep", CommonResult.class);
logger.info("orderService excep结束");
return result;
}
...
}
3.3 正常响应的请求
查看 gateway-6001 日志
2021-06-02 21:47:47.527 INFO [gateway,567fb1fda150a049,567fb1fda150a049,true] 5908 --- [ctor-http-nio-8] c.x.gateway.filters.LogGlobalFilter : 全局过滤器LogGlobeFilter开始：/ORDERSERVICE/order/getPayment/2
2021-06-02 21:47:47.527 INFO [gateway,567fb1fda150a049,567fb1fda150a049,true] 5908 --- [ctor-http-nio-8] c.x.gateway.filters.LogGlobalFilter : 全局过滤器LogGlobeFilter结束：/ORDERSERVICE/order/getPayment/2
查库 consumer-order8001 日志
2021-06-02 21:47:47.620 INFO [orderService,567fb1fda150a049,9b3210540bb54746,true] 21180 --- [nio-8001-exec-1] c.x.o.controller.OrderController : orderService getPayment开始，id=2
2021-06-02 21:47:47.621 INFO [orderService,567fb1fda150a049,9b3210540bb54746,true] 21180 --- [nio-8001-exec-1] c.x.o.controller.OrderController : orderService getPayment request headers，name=x-b3-traceid ------ value=567fb1fda150a049
2021-06-02 21:47:47.621 INFO [orderService,567fb1fda150a049,9b3210540bb54746,true] 21180 --- [nio-8001-exec-1] c.x.o.controller.OrderController : orderService getPayment request headers，name=x-b3-spanid ------ value=9b3210540bb54746
2021-06-02 21:47:47.621 INFO [orderService,567fb1fda150a049,9b3210540bb54746,true] 21180 --- [nio-8001-exec-1] c.x.o.controller.OrderController : orderService getPayment request headers，name=x-b3-parentspanid ------ value=567fb1fda150a049
2021-06-02 21:47:47.621 INFO [orderService,567fb1fda150a049,9b3210540bb54746,true] 21180 --- [nio-8001-exec-1] c.x.o.controller.OrderController : orderService getPayment request headers，name=x-b3-sampled ------ value=1
...
2021-06-02 21:47:47.958 INFO [orderService,567fb1fda150a049,9b3210540bb54746,true] 21180 --- [nio-8001-exec-1] c.x.o.controller.OrderController : orderService getPayment结束，id=2
查库 provider-payment9001 日志
2021-06-02 21:47:47.945 INFO [paymentService,567fb1fda150a049,62116299f6e392b4,true] 16396 --- [nio-9001-exec-2] c.x.p.controller.PaymentController : paymentService getPaymentById开始，id=2
2021-06-02 21:47:47.946 INFO [paymentService,567fb1fda150a049,62116299f6e392b4,true] 16396 --- [nio-9001-exec-2] c.x.p.controller.PaymentController : paymentService getPaymentById结束，id=2
可以看到上面的日志中，多了一些信息，比如 [gateway,9ac06290177336bf,9ac06290177336bf,true]，格式是 [appname,traceId,spanId,exportable]。
- appname：当前应用程序的名称，spring.application.name。
- traceId：当前跟踪链路的ID。
- spanId：当前操作的Span ID。
- exportable：是否被sleuth采样，将跟踪数据导出到Zipkin。
http://localhost:9411 打开zipkin的web UI，可以查询到一条跟踪链路：
点击“依赖”也可搜索到3个服务的依赖关系图：
3.4 异常请求
启动服务，在访问 http://localhost:6001/ORDERSERVICE/order/excep ，请求失败
在 zipkin 的web UI 上查看异常的跟踪链路，可以看到每个服务发生异常的原因：
代码：
github.com/wengxingxia/006SpringCloud.git
随时随地看视频
