一、链路追踪Sleuth
1、订单访问时长的分析
1、我们在微服务shop-product-service的查询方法中加入延时操作。
@RestController
@RequestMapping("/products")
public class ProductController {
@Autowired
private ProductService productService;
@ResponseStatus(HttpStatus.OK)
@GetMapping("/{id}")
public R<ProductDto> getById(@PathVariable("id") Long id) throws InterruptedException {
Thread.sleep(3 * 1000);
Product product = productService.getById(id);
ProductDto productDto = ProductConvert.INSTANCE.entity2dto(product);
return R.success().data(productDto);
}
}
2、访问微服务shop-order-service时发现请求时间为7.79s,经过多次测试都要这么长的时间。但是一个订单访问需要这么长的时间,肯定是那里出现了问题,关键是如何排查这些问题呢?
3、我们分析微服务shop-order-service的请求链路,帮助分析请求链路中的耗时情况。在开发时可以使用Debug方式查找程序运行的耗时点,但是在生产环境中不能用Debug方式。我们也可以在每个关键节点的开始和结束记录日志,然后计算执行时间,但是这种方式对程序的侵入性强。
这里引入链路追踪,相当于GPS,将整个请求过程中的关键点都记录下来,然后再分析这些数据,就可以得到整个请求过程的完整分析。
2、分布式链路追踪
(1)什么是分布式链路追踪
在大型系统的微服务化构建中,一个系统被拆分成了许多模块。这些模块负责不同的功能,组合成系统,最终可以提供丰富的功能。在这种架构中,一次请求往往需要涉及到多个服务。互联网应用构建在不同的软件模块集上,这些软件模块有可能是由不同的团队开发、可能使用不同的编程语言来实现、有可能布在了几千台服务器,横跨多个不同的数据中心,也就意味着这种架构形式也会存在一些问题:
1、如何快速发现问题?
2、如何判断故障影响范围?
3、如何梳理服务依赖以及依赖的合理性?
4、如何分析链路性能问题以及实时容量规划?
分布式链路追踪(Distributed Tracing),就是将一次分布式请求还原成调用链路,进行日志记录,性能监控并将一次分布式请求的调用情况集中展示。比如各个服务节点上的耗时、请求具体到达哪台机器上、每个服务节点的请求状态等等。
(2)常见的链路追踪技术
常见的链路追踪技术有下面这些:
Sleuth是SpringCloud提供的分布式系统中链路追踪解决方案。
zipkin由Twitter公司开源,开放源代码分布式的跟踪系统,用于收集服务的定时数据,以解决微服务架构中的延迟问题,包括:数据的收集、存储、查找和展现。该产品结合spring-cloud-sleuth使用较为简单,集成很方便,但是功能较简单。
cat由大众点评开源,基于Java开发的实时应用监控平台,包括实时应用监控,业务监控。集成方案是通过代码埋点的方式来实现监控,比如:拦截器、过滤器等。对代码的侵入性很大,集成成本较高。风险较大。
Pinpoint是韩国人开源的基于字节码注入的调用链分析,以及应用监控分析工具。特点是支持多种插件,UI功能强大,接入端无代码侵入。
SkyWalking是本土开源的基于字节码注入的调用链分析,以及应用监控分析工具。特点是支持多种插件,UI功能较强,接入端无代码侵入。目前已加入Apache孵化器。
(3)Sleuth + zipkin
Spring Cloud Alibaba技术栈中没有提供自己的链路追踪技术,这里采用SpringCloud官方提供的链路追踪解决方案Spring Cloud Sleuth。因为Sleuth没有UI界面,所以使用Sleuth收集链路追踪的数据,然后用Zinkin进行UI展示。
3、Spring Cloud Sleuth
(1)Sleuth简介
Spring Cloud Sleuth实现了分布式跟踪解决方案,兼容Zipkin、HTrace等日志追踪系统。
Spring Cloud Sleuth在整个分布式系统中能跟踪一个用户请求的过程,捕获这些跟踪数据,就能构建微服务的整个调用链的视图,这是调试和监控微服务的关键工具。
通过Spring Cloud Sleuth可以很方便的看出每个采样请求的耗时,分析哪些服务调用比较耗时,当服务调用的耗时随着请求量的增大而增大时,可以对服务的扩容提供一定的提醒。
(2)Sleuth设计思路
Spring Cloud Sleuth是在请求过程中传递唯一ID到每个方法来识别同一请求,然后在应用的各个常见入口点和出口点来采集数据,如servlet filter, rest template, scheduled actions, message channels, feign client等。
注意:
traceId表示一个请求分配的ID号,用来标识一条请求链路。
spanId表示一个基本工作单元。一个请求可以包含多个步骤,每个步骤都拥有自己的spanId,即一个请求包含一个TraceId和多个SpanId。
注意:即使日志消息来源于同一请求中的两个不同的类,TraceId在两条日志中是相同的,这样就可以在不同的日志中通过寻找traceid来识别一个请求。
(3)Sleuth核心概念
1、Trace
Trace由一组Trace Id相同的Span串联形成一个树状结构。
为了实现请求跟踪,当请求到达分布式系统的入口端点时,只需要服务跟踪框架为该请求创建一个唯一的标识(即TraceId),同时在分布式系统内部流转的时候,框架始终保持传递该唯一值,直到整个请求的返回。那么我们就可以使用该唯一标识将所有的请求串联起来,形成一条完整的请求链路。
例如:上图是一个完整的请求过程,从Service1进入的request到返回的response为止,整个过程中所有请求中附带的traceId是相同的,形成一条完整的请求链路。
2、Span
Span代表了一个基本的工作单元,一次单独的调用链可以称为一个Span。一次完整调用中所有Span都挂在一个特定的Trace上,即共用一个trace id。
为了统计各处理单元的延迟,当请求到达各个服务组件的时候,通过一个唯一标识(SpanId)来标记它的开始、具体过程和结束。通过SpanId的开始和结束时间戳,就能统计该span的调用时间,除此之外,我们还可以获取如事件的名称、请求信息等元数据。
例如,每个微服务左边调用时有一个SpanId,右边离开时也有一个SpanId,这四个SpanId构建一个基本的工作单元,可以实现各种计算。以Service2为例,它有2个SpanId,左边为SpanId=B,右边是SpanId=C。
3、Annotation
用它记录一段时间内的事件,内部使用的重要注释:
cs(Client Send)客户端发出请求,开始一个请求的生命
sr(Server Received)服务端接受到请求开始进行处理,sr-cs=网络延迟(服务调用的时间)
ss(Server Send)服务端处理完毕准备发送到客户端,ss-sr=服务器上的请求处理时间
cr(Client Reveived)客户端接受到服务端的响应,请求结束。cr-cs =请求的总时间
下面以订单微服务调用商品微服务为例,讲解这四个属性:
4、Sleuth与REST微服务
通过前面的项目案例整合Sleuth,完成入门案例的编写。
(1)添加Sleuth依赖
在需要加入链路跟踪的微服务中都要引入Sleuth依赖。
<!--链路追踪 Sleuth-->
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-sleuth</artifactId>
</dependency>
(2)Sleuth与日志的集成
spring-cloud-starter-sleuth默认提供了Sleuth与Logback的集成,在程序运行时Sleuth向日志系统的MDC中添加独特的Sleuth数据的标识符(traceId、parentId、spanId、spanExportable)。默认情况下,我们只需要配置日志输出内容,Seluth和Logback会自动集成,并且在控制台中输出日志记录里有Sleuth跟踪数据。
在shop-common-rest的logback-spring.xml中加入Seluth的输出信息。
<configuration scan="true" scanPeriod="10 seconds">
<contextName>logback</contextName>
<!-- <contextName>用来设置上下文名称,区分不同应用程序的记录 -->
<springProperty scope="context" name="APP_NAME" source="spring.application.name" />
<!-- %X{traceId:-}等是sleuth提供的随机字符串,由sleuth负责填充。 -->
<property name="CONSOLE_LOG_PATTERN"
value="%yellow(%date{yyyy-MM-dd HH:mm:ss}) |%highlight(%-5level) |[${APP_NAME},%X{traceId:-},%X{parentId:-},%X{spanId:-},%X{spanExportable:-}] |%blue(%thread) |%blue(%file:%line) |%green(%logger) |%cyan(%msg%n)"/>
<!--输出到控制台-->
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<!--日志级别-->
<level>DEBUG</level>
</filter>
<encoder>
<!--日志格式-->
<Pattern>${CONSOLE_LOG_PATTERN}</Pattern>
<!--日志字符集-->
<charset>${ENCODING}</charset>
</encoder>
</appender>
<!--可以灵活设置此处,从而控制日志的输出-->
<root level="DEBUG">
<appender-ref ref="CONSOLE" />
</root>
</configuration>
(3)与Sleuth集成日志记录
我们运行程序后,访问“http://localhost:57022/orders?productId=1”看到控制台中日志记录中有Sleuth的跟踪数据。注意:只有Sleuth跟踪的组件才会生成带跟踪数据的日志。
在shop-order-service中有下面的跟踪记录:
2021-04-08 10:16:09.472 INFO [shop-order-service,9046a6b1b6b8f7f2,9046a6b1b6b8f7f2] 18668 --- [io-57021-exec-1] io.seata.tm.TransactionManagerHolder : TransactionManager Singleton io.seata.tm.DefaultTransactionManager@12d70c18
2021-04-08 10:16:09.509 INFO [shop-order-service,9046a6b1b6b8f7f2,9046a6b1b6b8f7f2] 18668 --- [io-57021-exec-1] i.seata.tm.api.DefaultGlobalTransaction : Begin new global transaction [192.168.0.103:8091:54163120536727714]
2021-04-08 10:16:09.512 INFO [shop-order-service,9046a6b1b6b8f7f2,9046a6b1b6b8f7f2] 18668 --- [io-57021-exec-1] c.s.order.controller.OrderController : >>客户下单,使用1号调用商品微服务查询商品信息
在shop-product-service中有下面的跟踪记录:
2021-04-08 10:16:10.869 WARN [shop-product-service,9046a6b1b6b8f7f2,65542266c5cfde05] 25400 --- [io-57020-exec-1] c.a.druid.pool.DruidAbstractDataSource : discard long time none 2021-04-08 10:16:11.059 ERROR [shop-product-service,9046a6b1b6b8f7f2,65542266c5cfde05] 25400 --- [io-57020-exec-1] c.s.c.c.e.h.ClimbRestExceptionHandler : ExceptionControllerAdvice.handleException.
其中9046a6b1b6b8f7f2是TraceId,9046a6b1b6b8f7f2和65542266c5cfde05是SpanId。我们每次调用都有一个全局的TraceId将调用链路串起来,每个微服务内部都有一个SpanId。仔细分析每个微服务的日志,不难看出请求的具体过程。
当然,查看日志文件并不是一个很好的方法,当微服务越来越多日志文件也会越来越多,通过Zipkin可以将日志聚合,并进行可视化展示和全文检索。
二、分布式跟踪系统Zipkin
1、Zipkin介绍
Zipkin是Twitter的一个开源项目,它基于Google Dapper实现,致力于收集服务的定时数据,以解决微服务架构中的延迟问题,包括数据的收集、存储、查找和展现。
我们可以使用它来收集各个服务器上请求链路的跟踪数据,并通过它提供的REST API接口来辅助我们查询跟踪数据,以实现对分布式系统的监控程序,从而及时地发现系统中出现的延迟升高问题,并找出系统性能瓶颈的根源。
除了面向开发的API接口之外,它也提供了方便的UI组件来帮助我们直观的搜索跟踪信息和分析请求链路明细,比如:可以查询某段时间内各用户请求的处理时间等。
Zipkin提供了可插拔数据存储方式:In-Memory、MySql、Cassandra以及Elasticsearch。这里使用默认的In-Memory存储方式。
2、基于Docker的Zipkin服务器安装
Zipkin分为服务端和客户端,通常客户端也就是微服务应用。
1、首先下载Docker镜像openzipkin/zipkin。
docker pull openzipkin/zipkin
2、运行镜像openzipkin/zipkin,并且映射默认端口9411。
docker run -d --name zipkin-server -p 9411:9411 openzipkin/zipkin
3、在浏览器中访问Zipkin服务器。
http://192.168.0.106:9411/zipkin/
这个界面可以根据服务名、开始时间、结束时间、请求消耗的时间等条件来查找服务的调用情况。点击“Find Trackes”按钮可以查看服务的调用情况,比如服务调用时间、服务的消耗时间,服务调用的链路情况。点击Dependences按钮可以查看服务的依赖关系,在本案例中,shop-order-service将请求转发到了shop-product-service。
3、微服务中集成Zipkin客户端
(1)Zipkin客户端集成
spring-cloud-starter-zipkin是Sleuth和Zipkin集成包,引入了spring-cloud-starter-sleuth和spring-cloud-sleuth-zipkin依赖。
在每个需要链路跟踪的微服务中加入下面依赖。
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-zipkin</artifactId>
<version>2.2.8.RELEASE</version>
</dependency>
(2)Sleuth和Zipkin的集成
Spring Cloud Sleuth将Sleuth收集跟踪信息可以通过HTTP请求发给Zipkin服务器,利用Zipkin的存储来存储信息,利用Zipkin UI来展示数据。
客户端中用spring.zipkin.baseUrl指定的Zipkin服务器的位置,一旦发生服务间的调用的时候,就会被配置在微服务里面的Sleuth的监听器监听,并生成相应的Trace和Span信息发送给Zipkin服务端。
在每个微服务中添加zipkin服务器的配置。
spring:
zipkin:
#zipkin server的请求地址
base-url: http://192.168.0.106:9411/
#让nacos把zipkin当成一个URL,不要当做服务名
discoveryClientEnabled: false
(3)随机取样
Sleuth使用采样器Sampler来采集跟踪数据,默认使用RateLimitingSampler。如果服务的流量很大,所有数据全部采集将对传输和存储的压力比较大。这个时候可以设置采样率,Sleuth可以通过配置“spring.sleuth.sampler.probability=X.Y”(如配置为1.0,则采样率为100%,采集服务的全部追踪数据),若不配置默认采样率是0.1(即10%)。
下面是随机采样的配置。这里设置为1.0是要求获取所有跟踪数据。
spring:
sleuth:
sampler:
#采样的百分比,可以在0.0-1.0之间调整数据
probability: 1.0
(4)测试链路跟踪
我们访问订单微服务http://localhost:57022/orders?productId=1,在Zipkin服务器中点击“RUN QUERY”来查询Zipkin中的跟踪信息,可以看到之前访问订单微服务的跟踪信息。
1、访问订单微服务
http://localhost:57022/orders?productId=1
在各个微服务的控制台中可以看到将跟踪数据写入到了Zipkin中。
ZipkinRestTemplateWrapper - HTTP POST http://192.168.0.107:9411/api/v2/spans
ZipkinRestTemplateWrapper - Writing [[B@e082f5c] as "application/json"
ZipkinRestTemplateWrapper - Response 202 ACCEPTED
2、在zipkin界面中点击“RUN QUERY”按钮,观察到访问订单微服务的链路跟踪效果。
3、点击其中一条记录的“Show”按钮,可观察一次访问的详细链路跟踪信息。
点击其中一条记录的“显示全部Annotations”按钮,还可以查看内部的详细数据。
通过这里的数据分析,我们可以看到花费时间最多的在微服务shop-product-service中,对应的请求是“get /products/{id}”。