本文是Spring Cloud专栏的第九篇文章,了解前八篇文章内容有助于更好的理解本文:
- Spring Cloud快速开发入门第一篇---SpringCloud前言及其常用组件介绍概览
- Spring Cloud快速开发入门第二篇---使用并认识Eureka注册中心
- Spring Cloud快速开发入门第三篇---搭建高可用Eureka注册中心
- Spring Cloud快速开发入门第四篇---客户端负载均衡Ribbon
- Spring Cloud快速开发入门第五篇---服务熔断Hystrix
- Spring Cloud快速开发入门第六篇---Hystrix仪表盘监控Hystrix Dashboard
- Spring Cloud快速开发入门第七篇---声明式服务调用Feign
- Spring Cloud快速开发入门第八篇---Hystrix集群监控Turbine
一、Sleuth前言
随着业务的发展,系统规模也会变得越来越大,各微服务间的调用关系也变得越来越错综复杂。通常一个由客户端发起的请 求在后端系统中会经过多个不同的微服务调用来协同产生最后的请求结果,在复杂的微服 务架构系统中,几乎每一个前端请求都会形成一条复杂的分布式服务调用链路,在每条链路中任何一个依赖服务出现延迟过高或错误的时候都有可能引起请求最后的失败。这时候, 对于每个请求,全链路调用的跟踪就变得越来越重要,通过实现对请求调用的跟踪可以帮 助我们快速发现错误根源以及监控分析每条请求链路上的性能瓶颈等。
针对上面所述的分布式服务跟踪问题, Spring Cloud Sleuth提供了一套完整的解决方案。在本文中,我们将详细介绍如何使用 Spring Cloud Sleuth来为微服务架构增加分布式服务跟踪的能力。
二、Sleuth快速入门
2-1、搭建一个消费者(springcloud-consumer-sleuth),提供者(springcloud-consumer-sleuth),消费者和提供者都是和前面所用的都一样没有什么区别,注册中心(还是使用前面案例的注册中心)
2-2、完成以上工作之后,我们为服务提供者和服务消费者添加跟踪功能,通过Spring Cloud Sleuth的封装,我们为应用增加服务跟踪能力的操作非常方便,只需要在服务提供者和服务消费者增加spring-cloud-starter-sleuth依赖即可
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-sleuth</artifactId>
</dependency>
2-3、访问消费者接口,然后查看控制台日志显示
消费者:
INFO [springcloud-consumer-sleuth,f6fb983680aab32b,f6fb983680aab32b,false] 8992 --- [nio-9090-exec-1] c.s.controller.SleuthConsumerController : === consumer hello ===
提供者:
INFO [springcloud-provider-sleuth,f6fb983680aab32b,c70932279d3b3a54,false] 788 --- [nio-8080-exec-1] c.s.controller.SleuthProviderController : === provider hello ===
从上面的控制台输出内容中,我们可以看到多了一些形如 [springcloud-consumer-sleuth,f6fb983680aab32b,c70932279d3b3a54,false]的日志信息,而这些元素正是实现分布式服务跟踪的重要组成部分,每个值的含义如下所述。
- 第一个值: springcloud-consumer-sleuth,它记录了应用的名称,也就是 application properties 中 spring. application.name参数配置的属性
- 第二个值:f6fb983680aab32b, Spring Cloud Sleuth生成的一个ID,称为 Trace ID, 它用来标识一条请求链路。一条请求链路中包含一个 Trace ID,多个 Span ID
- 第三个值:c70932279d3b3a54, Spring Cloud Sleuth生成的另外一个ID,称为 Span ID,它表示一个基本的工作单元,比如发送一个HTTP请求
- 第四个值: false,表示是否要将该信息输出到 Zipkin等服务中来收集和展示。 上面四个值中的 Trace ID和 Span ID是 Spring Cloud Sleuth实现分布式服务跟踪的核心,在一次服务请求链路的调用过程中,会保持并传递同 一个 Trace ID,从而将整个分 布于不同微服务进程中的请求跟踪信息串联起来。以上面输出内容为例, springcloud-consumer-sleuth和springcloud-provider-sleuth同属于一个前端服务请求资源,所以他们的Trace ID是相同的,处于同一条请求链路中。
三、跟踪原理
分布式系统中的服务跟踪在理论上并不复杂,它主要包括下面两个关键点。
- 为了实现请求跟踪,当请求发送到分布式系统的入口端点时,只需要服务跟踪框架为该请求创建一个唯一的跟踪标识,同时在分布式系统内部流转的时候,框架始终保持传递该唯一标识,直到返回给请求方为止,这个唯一标识就是前文中提到的 Trace ID。通过 Trace ID的记录,我们就能将所有请求过程的日志关联起来
- 为了统计各处理单元的时间延迟,当请求到达各个服务组件时,或是处理逻辑到达某个状态时,也通过一个唯一标识来标记它的开始、具体过程以及结束,该标识就 是前文中提到的 Span ID。对于每个Span来说,它必须有开始和结束两个节点,通过记录开始Span和结束Span的时间戳,就能统计出该Span的时间延迟,除了时间 戳记录之外,它还可以包含一些其他元数据,比如事件名称、请求信息等。
在快速入门示例中,我们轻松实现了日志级别的跟踪信息接入,这完全归功于spring-cloud-starter-sleuth组件的实现,在SpringBoot应用中,通过在工程中引入spring-cloud-starter-sleuth依赖之后,他会自动为当前应用构建起各通信通道的跟踪机制,比如:
- 通过诸如 RabbitMQ、Kaka(或者其他任何 Spring Cloud Strean绑定器实现的消息中间件)传递的请求。
- 通过Zuul代理传递的请求。
- 通过 RestTemplate发起的请求。
在快速入门示例中,由于springcloud-consumer-sleuth对springcloud-provider-sleuth发起的请求是通过 RestTemplate 实现的,所以 spring-cloud-starter-sleuth组件会对该请求进行处理。在发送到springcloud-provider-sleuth之前, Sleuth会在该请求的 Header中增加实现跟踪需要的重要信息,主要有下面 这几个(更多关于头信息的定义可以通过查看org.springframework.cloud.sleuth.Span的源码获取)。
- X-B3-TraceId:一条请求链路( Trace)的唯一标识,必需的值。
- X-B3- SpanId:一个工作单元(Span)的唯一标识,必需的值。
- X-B3- ParentSpanId:标识当前工作单元所属的上一个工作单元, Root Span(请求链路的第一个工作单元)的该值为空。
- X-B3-Sampled:是否被抽样输出的标志,1表示需要被输出,0表示不需要被输出。
- X-B3-Name:工作单元的名称
可以通过对 的实现做一些修改来输出这些头信息,具体如下:
private final Logger logger = Logger.getLogger(SleuthProviderController.class.getName());
@RequestMapping("/hello")
public String hello(HttpServletRequest request){
logger.info("=== provider hello ===,Traced={"+request.getHeader("X-B3-TraceId")+"},SpanId={"+request.getHeader("X-B3- SpanId")+"}");
return "Trace";
}
通过上面的改造,在次重启案例,然后访问我们查看日志,可以看到提供者输出了正在处理的TraceId和SpanId信息。
INFO [springcloud-consumer-sleuth,41697d7fa118c150,41697d7fa118c150,false] 10036 --- [nio-9090-exec-2] c.s.controller.SleuthConsumerController : === consumer hello ===
INFO [springcloud-provider-sleuth,41697d7fa118c150,863a1245c86b580e,false] 11088 --- [nio-8080-exec-1] c.s.controller.SleuthProviderController : === provider hello ===,Traced={41697d7fa118c150},SpanId={863a1245c86b580e}
四、抽样收集
通过 Trace ID和 Span ID已经实现了对分布式系统中的请求跟踪,而记录的跟踪信息最终会被分析系统收集起来,并用来实现对分布式系统的监控和分析功能,比如,预警延 迟过长的请求链路、查询请求链路的调用明细等。此时,我们在对接分析系统时就会碰到 个问题:分析系统在收集跟踪信息的时候,需要收集多少跟踪信息才合适呢?
理论上来说,我们收集的跟踪信息越多就可以越好地反映出系统的实际运行情况,并 给出更精准的预警和分析。但是在高并发的分布式系统运行时,大量的请求调用会产生海量的跟踪日志信息,如果收集过多的跟踪信息将会对整个分布式系统的性能造成一定的影响,同时保存大量的日志信息也需要不少的存储开销。所以,在Sleuth中采用了抽象收集的方式来为跟踪信息打上收集标识,也就是我们之前在日志信息中看到的第4个布尔类型的值,他代表了该信息是否被后续的跟踪信息收集器获取和存储。
public abstract class Sampler {
/**
* Returns true if the trace ID should be measured.
*
* @param traceId The trace ID to be decided on, can be ignored
*/
public abstract boolean isSampled(long traceId);
}
通过实现 isSampled方法, Spring Cloud Sleuth会在产生跟踪信息的时候调用它来为跟踪信息生成是否要被收集的标志。需要注意的是,即使isSampled返回了false,它仅代表该跟踪信息不被输出到后续对接的远程分析系统(比如 Zipkin,对于请求的跟踪活动依然会进行,所以我们在日志中还是能看到收集标识为fase的记录。
默认情况下, Sleuth会使用 SamplerProperties实现的抽样策略,以请求百分比的方式配置和收集跟踪信息。我们可以通过在 application.yml中配置下面的参数对其百分比值进行设置,它的默认值为0.1,代表收集10%的请求跟踪信息。
spring:
sleuth:
sampler:
probability: 0.1
spring.sleuth.sampler.percentage=0.1 在开发调试期间,通常会收集全部跟踪信息并输岀到远程仓库,我们可以将其值设置为1,或者也可以注入Sampler对象 SamplerProperties策略,比如
@Bean
public Sampler defaultSampler() {
return Sampler.ALWAYS_SAMPLE;
}
由于跟踪日志信息数据的价值往往仅在最近一短时间内非常有用,比如一周。那么我们在设计抽样策略时,主要考虑在不对系统造成明显性能影响的情况下,以在日志保留时间窗内充分利用存储空间的原则来实现抽样策略。
五、与Zipkin整合
由于日志文件都离散地存储在各个服务实例的文件系之上,仅通过查看日志信息文件来分我们的请求链路依然是一件相当麻烦的事情,所以我们需要一些工具来帮助集中收集、存储和搜索这些跟踪信息,比如ELK日志平台,虽然通过ELK平台提供的收集、存储、搜索等强大功能,我们对跟踪信息的管理和使用已经变得非常便利。但是,在ELK平台中的数据分析维度缺少对请求链路中各阶段时间 延迟的关注,很多时候我们追溯请求链路的一个原因是为了找出整个调用链路中出现延迟过高的瓶颈源,或为了实现对分布式系统做延迟监控等与时间消耗相关的需求,这时候类似ELK这样的日志分析系统就显得有些乏力了。对于这样的问题,我们就可以引入Zipkin 来得以轻松解决。
Zipkin是Twitter的一个开源项目,它基于 Google Dapper实现。我们可以使用它来收集各个服务器上请求链路的跟踪数据,并通过它提供的 REST API接口来辅助査询跟踪数据以实现对分布式系统的监控程序,从而及时发现系统中出现的延迟升高问题并找出系统 性能瓶颈的根源。除了面向开发的API接口之外,它还提供了方便的UI组件来帮助我们 直观地搜索跟踪信息和分析请求链路明细,比如可以査询某段时间内各用户请求的处理时间等。
下图展示了Zipkin的基础架构,他主要由4个核心组成。
- Collector:收集器组件,它主要处理从外部系统发送过来的跟踪信息,将这些信息 转换为 Zipkin内部处理的Span格式,以支持后续的存储、分析、展示等功能。
- Storage:存储组件,它主要处理收集器接收到的跟踪信息,默认会将这些信息存储 在内存中。我们也可以修改此存储策略,通过使用其他存储组件将跟踪信息存储到 数据库中。
- RESTful API:API组件,它主要用来提供外部访问接口。比如给客户端展示跟踪信 息,或是外接系统访问以实现监控等。
- Web UI:UI组件,基于AP组件实现的上层应用。通过UI组件,用户可以方便而 又直观地查询和分析跟踪信息。
5-1、构建server-zipkin
在spring Cloud为F版本的时候,已经不需要自己构建Zipkin Server了,只需要下载jar即可,下载地址:https://dl.bintray.com/openzipkin/maven/io/zipkin/java/zipkin-server/
5-2、下载完成jar 包之后,需要运行jar,如下:
java -jar zipkin-server-2.10.1-exec.jar
访问浏览器http://localhost:9411,如图我们可以看到zipkin的管理界面
5-3、为应用引入和配置Zipkin服务
我们需要对应用做一些配置,以实现将跟踪信息输出到Zipkin Server。我们以前实现的消费者(springcloud-consumer-sleuth),提供者(springcloud-provider-sleuth)为例,对他们进行改造,都加入整合Zipkin的依赖
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-zipkin</artifactId>
</dependency>
5-4、在消费者(springcloud-consumer-sleuth),提供者(springcloud-provider-sleuth)中增加Zipkin Server的配置信息,具体信息如下所示,默认是连接地址为:http://localhost:9411
spring:
zipkin:
base-url: http://localhost:9411
5-5、测试与分析
到这里我们已经完成了介入Zipkin Server的所有基本工作,然后访问几次消费者接口http://localhost:9090/consumer/hello,当在日志中出现跟踪信息的最后一个值为true的时候,说明该跟踪信息会输出给Zipkin Server,如下日志
2019-08-12 15:44:20.505 INFO [springcloud-provider-sleuth,27fb6ab4356aa407,38e45d3e7814ecc9,false] 6388 --- [nio-8080-exec-5] c.s.controller.SleuthProviderController : === provider hello ===,Traced={27fb6ab4356aa407},SpanId={38e45d3e7814ecc9}
2019-08-12 15:44:21.415 INFO [springcloud-provider-sleuth,2a4d2543362aac95,62b7fcee09987975,false] 6388 --- [nio-8080-exec-6] c.s.controller.SleuthProviderController : === provider hello ===,Traced={2a4d2543362aac95},SpanId={62b7fcee09987975}
2019-08-12 15:44:25.976 INFO [springcloud-provider-sleuth,0f03bead2cdbe9c6,2ad8a255addb8202,false] 6388 --- [nio-8080-exec-7] c.s.controller.SleuthProviderController : === provider hello ===,Traced={0f03bead2cdbe9c6},SpanId={2ad8a255addb8202}
2019-08-12 15:44:26.811 INFO [springcloud-provider-sleuth,ef9b635c55303722,c52678e7be0936e7,false] 6388 --- [nio-8080-exec-8] c.s.controller.SleuthProviderController : === provider hello ===,Traced={ef9b635c55303722},SpanId={c52678e7be0936e7}
2019-08-12 15:44:27.586 INFO [springcloud-provider-sleuth,fefde5b58c804046,097ef02d382be3ad,false] 6388 --- [nio-8080-exec-9] c.s.controller.SleuthProviderController : === provider hello ===,Traced={fefde5b58c804046},SpanId={097ef02d382be3ad}
2019-08-12 15:44:29.468 INFO [springcloud-provider-sleuth,cb9952a96fbf430e,d40b9adbe70d3c13,false] 6388 --- [io-8080-exec-10] c.s.controller.SleuthProviderController : === provider hello ===,Traced={cb9952a96fbf430e},SpanId={d40b9adbe70d3c13}
2019-08-12 15:44:30.285 INFO [springcloud-provider-sleuth,c8003c26121a3ad2,5d3817c751815709,false] 6388 --- [nio-8080-exec-1] c.s.controller.SleuthProviderController : === provider hello ===,Traced={c8003c26121a3ad2},SpanId={5d3817c751815709}
2019-08-12 15:44:34.873 INFO [springcloud-provider-sleuth,b221d9203ee5e84e,1cf46801244f0e28,false] 6388 --- [nio-8080-exec-2] c.s.controller.SleuthProviderController : === provider hello ===,Traced={b221d9203ee5e84e},SpanId={1cf46801244f0e28}
2019-08-12 15:44:35.163 INFO [springcloud-provider-sleuth,e65685341074094e,900d7c7c2440cc71,false] 6388 --- [nio-8080-exec-3] c.s.controller.SleuthProviderController : === provider hello ===,Traced={e65685341074094e},SpanId={900d7c7c2440cc71}
2019-08-12 15:44:35.358 INFO [springcloud-provider-sleuth,c518cdbaf673d334,8610f92ab8ea9d63,false] 6388 --- [nio-8080-exec-4] c.s.controller.SleuthProviderController : === provider hello ===,Traced={c518cdbaf673d334},SpanId={8610f92ab8ea9d63}
2019-08-12 15:44:35.547 INFO [springcloud-provider-sleuth,093c1c9b23515258,e699e9336965ce5d,true] 6388 --- [nio-8080-exec-5] c.s.controller.SleuthProviderController : === provider hello ===,Traced={093c1c9b23515258},SpanId={e699e9336965ce5d}
2019-08-12 15:44:35.725 INFO [springcloud-provider-sleuth,50c1e630f6e1565b,1024d86edcbccf97,false] 6388 --- [nio-8080-exec-6] c.s.controller.SleuthProviderController : === provider hello ===,Traced={50c1e630f6e1565b},SpanId={1024d86edcbccf97}
2019-08-12 15:44:35.891 INFO [springcloud-provider-sleuth,13e1bc9b7d3f9fcd,0b2fa9b2e14cf59c,false] 6388 --- [nio-8080-exec-7] c.s.controller.SleuthProviderController : === provider hello ===,Traced={13e1bc9b7d3f9fcd},SpanId={0b2fa9b2e14cf59c}
2019-08-12 15:44:36.057 INFO [springcloud-provider-sleuth,75d25e4432832a4d,81371d963b62df6d,false] 6388 --- [nio-8080-exec-8] c.s.controller.SleuthProviderController : === provider hello ===,Traced={75d25e4432832a4d},SpanId={81371d963b62df6d}
所以此时可以在Zipkin Server的管理界面中选择合适的查询条件,单击Find Traces按钮,就可以查询出刚才在日志中出现的跟踪信息了(也可以根据日志信息中的Treac ID,在页面有上角的输入框中来搜索),页面如下所示:
点击下方springcloud-consumer-sleuth 端点的跟踪信息,还可以得到Sleuth 跟踪到的详细信息,其中包括我们关注的请求时间消耗等。
点击导航栏中的《依赖分析》菜单,还可以查看Zipkin Server根据跟踪信息分析生成的系统请求链路依赖关系图,如下所示