SpringCloud之Sleuth全链路日志跟踪
1 Sleuth链路跟踪
本篇文章所涉及到的demo练习 使用的 springcloud 2021.0.3+ springboot2.6.8
1.1 分布式系统面临的问题
在微服务框架中,一个由客户端发起的请求在后端系统中会经过多个不同的的服务节点调用来协同产生最后的请求结果,每一个次请求都会形成一条复杂的分布式服务调用链路,链路中的任何一环出现高延时或错误都会引起整个请求最后的失败。
image.png1.2 Sleuth是什么
官网:https://docs.spring.io/spring-cloud-sleuth/docs/current/reference/html/
Spring Cloud Sleuth
提供了一套完整的服务跟踪的解决方案。它会将服务与服务之间的调用给记录起来。可以快速的知道调用 用户服务,到底涉及到了哪些微服务,方便我们快速排查问题!
具体的功能如下几点:
- 将
跟踪
和跨度 ID
添加到Slf4J
,因此可以从日志聚合器中的给定跟踪或跨度中提取所有日志。 - 检测来自
Spring
应用程序的公共入口和出口点(servlet filter
,rest template
,scheduled actions
,message channels
,feign client
)。 - 如果
spring-cloud-sleuth-zipkin
可用,则应用程序将通过HTTP
生成和报告与Zipkin
兼容的跟踪。默认情况下,它将它们发送到localhost
(端口 9411)上的Zipkin
收集器服务。使用spring.zipkin.baseUrl
配置Zipkin
服务的位置。
1.3 Zipkin是什么
Spring Cloud Sleuth
对于分布式链路的跟踪仅仅是生成一些数据,这些数据不便于人类阅读,所以我们一般把这种跟踪数据上传给Zipkin Server
,由Zipkin
通过UI
页面统一进行数据的展示
1.4 链路监控相关术语
这些术语在官方文档当中也可以看到的:
-
span
(跨度):工作的基本单位。例如,发送RPC
是一个新的跨度,发送响应到RPC
也是如此。Span
还有其他数据,例如描述、时间戳事件、键值注释(标签)、导致它们的Span
的ID
和进程 ID
(通常是 IP 地址)。跨度可以启动和停止,并且它们会跟踪它们的时间信息。创建跨度后,必须在将来的某个时间点停止它 -
Trace
:一组跨度形成树状结构。 -
Annotation/Event
:用于及时记录某个事件的存在,有如下事件类型:-
cs
:Client Send
,客户端发送。客户已提出请求。此注释指示跨度的开始。 -
sr
:Server Received
,服务器端收到请求并开始处理它。cs
从此时间戳中减去时间戳揭示了网络延迟。 -
ss
:Server Send
,服务器发送。在请求处理完成时注释(当响应被发送回客户端时)。从这个时间戳中减去sr时间戳,可以看出服务器端处理请求所需的时间。 -
cr
:Client Received
,客户收到。表示跨度的结束。客户端已成功收到服务器端的响应。cs
从这个时间戳中减去时间戳,可以看出客户端从服务器接收响应所需的全部时间。
-
下图显示了Span和Trace在系统中的外观: 音符的每种颜色表示一个跨度(有七个跨度 - 从A到G)。
image.png
下图显示了 span
的父子关系的外观:
你可以继续创建跨度(带有no custom span指示的示例),也可以手动创建子跨度(带有custom span指示的示例)。
1.5 实战练习
1.5.1 pom.xml
<properties>
<maven.compiler.source>8</maven.compiler.source>
<maven.compiler.target>8</maven.compiler.target>
<project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
<springboot.version>2.6.8</springboot.version>
<springcloud.version>2021.0.3</springcloud.version>
</properties>
<dependencyManagement>
<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-dependencies</artifactId>
<version>${springboot.version}</version>
<type>pom</type>
<scope>import</scope>
</dependency>
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-dependencies</artifactId>
<version>${springcloud.version}</version>
<type>pom</type>
<scope>import</scope>
</dependency>
</dependencies>
</dependencyManagement>
<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-sleuth</artifactId>
</dependency>
</dependencies>
1.5.2 添加yml配置
server:
port: 8989
spring:
application:
name: sleuth-demo
1.5.3 添加控制器
@RestController
public class ExampleController {
private static final Logger log = LoggerFactory.getLogger(ExampleController.class);
@RequestMapping("/")
public String home() {
log.info("Hello world!");
return "Hello World!";
}
}
1.5.4 测试访问
测试访问:http://localhost:8989/ 访问后观察打印的日志
[sleuth-demo,a79df4de56426209,a79df4de56426209]
此条目对应于[application name,trace id, span id]
设置DispatcherServlet
日志级别过后可以看到如下日志:
logging.level.org.springframework.web.servlet.DispatcherServlet=DEBUG
image.png
1.6 Zipkin
1.6.1 下载与启动
下载最新版本2.23.18:
https://repo1.maven.org/maven2/io/zipkin/zipkin-server/2.23.18/zipkin-server-2.23.18-exec.jar
官网:https://zipkin.io/pages/quickstart.html
Zipkin
的gihub
地址:https://github.com/openzipkin/zipkin
下载好jar包后直接java -jar启动:
image.png
然后访问:http://localhost:9411/zipkin/
1.6.2 搭建链路监控步骤
首先我们要至少准备两个服务,并且是调用关系。这样我们才可以通过zipkin
来查看调用链。
这里我会搭建两个服务,一个是8989服务,一个是8990服务,然后8989服务的一个接口当中调用了8990当中的接口!
远程调用的时候这里使用的是openfeign,openfeign和RestTemplate都是远程调用框架,如果对RestTemplate
熟悉,用RestTemplate
也是可以的
点击了解OpenFeign
点击了解RestTemplate
1.6.2.1 搭建8990提供者
第一步:搭建8990提供者
添加pom依赖
这块有一个点需要注意一下,有的
springcloud
版本当中是没有对spring-cloud-starter-zipkin
进行版本控制的,所以这时候我们需要自己去声明版本号,2.2.8.RELEASE是截止到现在最新的版本!spring-cloud-starter-zipkin
依赖是集成了spring-cloud-starter-sleuth
依赖的,所以我们引用了zipkin
就可以不引用sleuth
了
<properties>
<maven.compiler.source>8</maven.compiler.source>
<maven.compiler.target>8</maven.compiler.target>
<project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
<springboot.version>2.6.8</springboot.version>
<springcloud.version>2021.0.3</springcloud.version>
</properties>
<dependencyManagement>
<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-dependencies</artifactId>
<version>${springboot.version}</version>
<type>pom</type>
<scope>import</scope>
</dependency>
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-dependencies</artifactId>
<version>${springcloud.version}</version>
<type>pom</type>
<scope>import</scope>
</dependency>
</dependencies>
</dependencyManagement>
<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-zipkin</artifactId>
<version>2.2.8.RELEASE</version>
</dependency>
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-openfeign</artifactId>
</dependency>
</dependencies>
添加yml配置
server:
port: 8990
spring:
application:
name: sleuth-provide
logging:
level:
org.springframework.web.servlet.DispatcherServlet: DEBUG
添加控制器,主要是为了测试调用链路,这个接口就随便写一下就可以了!
@RestController
@RequestMapping("/user")
public class UserController {
@GetMapping("/getUserList")
public String getUserList() {
return "user";
}
}
启动后测试访问:http://localhost:8990/user/getUserList
访问两次后打开:http://localhost:9411/zipkin
1.6.2.2 搭建8989消费者
添加pom依赖同服务提供者
添加yml配置
server:
port: 8989
spring:
application:
name: sleuth-demo
logging:
level:
org.springframework.web.servlet.DispatcherServlet: DEBUG
使用openfeign
就需要开启openfeign
的注解支持,在启动类添加@EnableFeignClients
添加openfeign
远程调用接口
@FeignClient(value = "userService", url = "http://localhost:8990")
public interface UserService {
@GetMapping("/user/getUserList")
String getUserList();
}
添加控制器
@RestController
public class ExampleController {
private static final Logger log = LoggerFactory.getLogger(ExampleController.class);
@Resource
private UserService userService;
@RequestMapping("/")
public String home() {
log.info("Hello world!");
return userService.getUserList();
}
}
测试访问
访问:http://localhost:8989/
首先我们观察两个服务的日志:会发现一个问题trace id
是一致的,原因就是8989调用了8990服务,他们属于是一个链路的。记住这一切并不是zipkin
帮我们实现的,而是Sleuth
。
也可以通过将zipkin
的依赖改为sleuth
然后执行链路,它id仍然是一样的。zipkin
可以把它当做就是一个带有可视化界面的jar包,项目当中集成zipkin
依赖主要是将sleuth
链路跟踪的数据,上传到zipkin
,由zipkin
对数据进行整理并在页面上展示了出来,真正实现链路跟踪的是sleuth
然后我们再观察一下zipkin的日志:
image.png
故意制造异常
在消费服务的接口上故意制造异常:
@GetMapping("/getUserList")
public String getUserList() {
int i = 1/0;
return "user";
}
制造完异常后重启,再进行访问http://localhost:8989/,然后观察日志:可以很直观的看到是哪些链路出现了问题。
通过这里我们可以拿到Trace ID
,有了Trace ID
我们可以去日志文件当中搜索Trace ID
快速定位bug原因!
然后我们还可以查看链路详情:通过下图可以很直观的看到是由SLEUTH-DEMO
调用SLEUTH-PROVIDE
服务的时候,SLEUTH-DEMO
服务接口产生的异常
假如不使用Sleuth
,在我们进行远程调用的时候报错了,实际上我们是看不到他是因为什么报错的,我们只知道调用他报错了,日志如下,要想真正知道报的什么异常还得去查看远程调用的服务日志,而且还得比对服务调用时间,来查看当时报错的日志。
1.6.2.3 sleuth相关配置
问题: 默认情况下,它将它们发送到 localhost(端口 9411)上的 Zipkin
收集器服务,假设我们微服务并不是都部署在一台机器,那应该怎么办呢?使用spring.zipkin.baseUrl
配置Zipkin
服务的位置。
spring:
application:
name: sleuth-demo
zipkin:
base-url: http://localhost:9411/ # 指定zipkin地址
sleuth:
sampler:
# 采样率值介于 0 到 1 之间,1 则表示全部采集
probability: 1
# 每秒采集的数量,默认是10,通过设置这个可以有效的避免消息过大
rate: 10
关于sleuth
的其他相关配置属性,可查看官网:
https://docs.spring.io/spring-cloud-sleuth/docs/current/reference/html/appendix.html#appendix
1.6.2.4 使用RabbitMQ向Zipkin发送消息的方式
官网:https://docs.spring.io/spring-cloud-sleuth/docs/current/reference/html/howto.html#howto
如何通过消息设置 Brave & Zipkin 的 Sleuth?
如果要使用
RabbitMQ
、Kafka
或ActiveMQ
而不是HTTP
,请添加spring-rabbit
或spring-kafka
依赖org.apache,activemq;activemq-client
项,默认目标名称是Zipkin
。如果使用 Kafka,则必须添加 Kafka 依赖项
这个是什么意思呢?首先我们要明白一点,zipkin
当中所展示的数据实际上都是由我们服务发送给zipkin
他才将数据清洗,并展示出来的。默认采用的是HTTP
请求方式来进行向zipkin
发送的。
在实际开发当中HTTP
请求方式,有时候势必会给我们服务器带来一些压力,并发量特别大的情况下,会占用大量线程。HTTP
请求讲究的是,我发送给你,然后并且收到你的消息回复,这条连接才算结束。
所以基于这一点zipkin
也给我们提供了可以通过消息中间件来进行发送,发送给消息中间件我们就不用管了,这样可以避免线程拥堵,目前支持RabbitMQ
和Kafka
、ActiveMQ
这里直接使用rabbitmq
来进行演示 其他同理
添加依赖
<dependency>
<groupId>org.springframework.amqp</groupId>
<artifactId>spring-rabbit</artifactId>
</dependency>
添加rabbitmq配置
spring:
application:
name: sleuth-demo
zipkin:
base-url: http://localhost:9411/
sender:
type: rabbit
rabbitmq:
host: 127.0.0.1
port: 5672
username: guest
password: guest
listener: # 这里配置了重试策略
direct:
retry:
enabled: true
sleuth:
sampler:
#采样率值介于 0 到 1 之间,1 则表示全部采集
probability: 1
rate: 10
修改Zipkin启动命令
关于Zipkin启动相关命令可查看:
https://github.com/openzipkin/zipkin/tree/master/zipkin-server
java -jar zipkin-server-2.23.18-exec.jar --RABBIT_ADDRESSES=127.0.0.1:5672 --RABBIT_USER=guest --RABBIT_PASSWORD=guest
参数:
-
RABBIT_ADDRESSES
:指定RabbitMQ
地址 -
RABBIT_USER
:RabbitMQ
登录用户名 (默认quest) -
RABBIT_PASSWORD
:RabbitMQ
登录密码 (默认guest)
docker启动:
docker run \
--name zipkin-server2 -d \
--restart=always \
-p 9411:9411 \
-e RABBIT_ADDRESSES=162.14.115.18:5672 \
-e RABBIT_USER=admin \
-e RABBIT_PASSWORD=admin \
openzipkin/zipkin:2.21.7
测试,启动我们的服务,然后访问接口http://localhost:8989/
zipkin
就是自动创建的队列,通过这个队列进行发送消息的
打开zipkin
仍然可以看到调用信息。
Sleuth
到底给Zipkin
都发送了哪些数据?
想知道这个其实非常简单,我们只需要将zipkin
给停止掉,然后调用我们的服务接口即可。这时候队列当中的消息就没有人消费了,然后我们就可以通过RabbitMQ
管理页直接获取消息。
1.6.3 Zipkin配置持久化
假如不配置zipkin
持久化,当我们把jar
包给停止后,所有收集到的消息会直接清除!针对于数据持久化zipkin
提供了好几种种方式,常用的有两种,一种存储到mysql
,另一种是Elasticsearch
持久化到mysql
SQL文件:https://github.com/openzipkin/zipkin/blob/master/zipkin-storage/mysql-v1/src/main/resources/mysql.sql
官网配置:https://github.com/openzipkin/zipkin/tree/master/zipkin-server
配置持久化相当简单,只需要在mysql创建一个库和表,然后zipkin启动的时候指定持久化方式为mysql即可。
java -jar zipkin-server-2.23.18-exec.jar --STORAGE_TYPE=mysql --MYSQL_HOST=127.0.0.1 --MYSQL_TCP_PORT=3306 --MYSQL_DB=zipkin --MYSQL_USER=root --MYSQL_PASS=root --RABBIT_ADDRESSES=127.0.0.1:5672 --RABBIT_USER=guest --RABBIT_PASSWORD=guest
1.7 引入sleuth怎么输出traceId
首先我们要找到SpringBoot
默认的logback
配置
base.xml
引用了console-appender.xml
和defaults.xml
我们之所以不配置日志,springboot
也可以控制打印日志主要是以下:
CONSOLE_LOG_PATTERN
就是springboot
默认的日志格式:日志格式当中使用到了一个LOG_DATEFORMAT_PATTERN
变量
主要是由TraceEnvironmentPostProcessor
类当中的postProcessEnvironment
方法在启动的时候判断是否开启了sleuth
,假如开启了会直接设置LOG_DATEFORMAT_PATTERN
变量。
1.8 logback日志问题
分布式系统中,如何快速定位某个用户的请求日志?
由于
zikpin
并没有提供详细报错日志,例如是哪行报错,通过zipkin
我们可以知道是链路中哪个服务报错,这时候我们可以通过traceid
去日志文件当中查看详细报错信息
但是有时候我们项目当中使用了logback.xml
,日志格式里面并没有设置traceid
。那到底应该如何设置呢?
我们可以参考springboot
默认的日志配置,然后配置如下:
<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="60 seconds" debug="false">
<!-- 参考SpringBoot默认的logback配置,增加了error日志文件 -->
<!-- org/springframework/boot/logging/logback/base.xml -->
<conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter" />
<conversionRule conversionWord="wex" converterClass="org.springframework.boot.logging.logback.WhitespaceThrowableProxyConverter" />
<conversionRule conversionWord="wEx" converterClass="org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter" />
<property name="LOG_PATH" value="./logs"/>
<property name="CONSOLE_LOG_PATTERN" value="${CONSOLE_LOG_PATTERN:-%clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd HH:mm:ss.SSS}}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>
<property name="FILE_LOG_PATTERN" value="${FILE_LOG_PATTERN:-%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd HH:mm:ss.SSS}} ${LOG_LEVEL_PATTERN:-%5p} ${PID:- } --- [%t] %-40.40logger{39} : %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>
<!-- 控制台日志 -->
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>${CONSOLE_LOG_PATTERN}</pattern>
</encoder>
</appender>
<!--获取比info级别高(包括info级别)但除error级别的日志-->
<appender name="file_info" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${LOG_PATH}/sys-info.log</file>
<!-- 循环政策:基于时间创建日志文件 -->
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<!-- 日志文件名格式 -->
<fileNamePattern>${LOG_PATH}/sys-info.%d{yyyy-MM-dd}.log</fileNamePattern>
<!-- 日志最大的历史 60天 -->
<maxHistory>60</maxHistory>
</rollingPolicy>
<encoder>
<pattern>${FILE_LOG_PATTERN}</pattern>
</encoder>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>DENY</onMatch>
<onMismatch>ACCEPT</onMismatch>
</filter>
</appender>
<appender name="file_error" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${LOG_PATH}/sys-error.log</file>
<!-- 循环政策:基于时间创建日志文件 -->
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<!-- 日志文件名格式 -->
<fileNamePattern>${LOG_PATH}/sys-error.%d{yyyy-MM-dd}.log</fileNamePattern>
<!-- 日志最大的历史 60天 -->
<maxHistory>60</maxHistory>
</rollingPolicy>
<encoder>
<pattern>${FILE_LOG_PATTERN}</pattern>
</encoder>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<!-- 过滤的级别 -->
<level>ERROR</level>
<!-- 匹配时的操作:接收(记录) -->
<onMatch>ACCEPT</onMatch>
<!-- 不匹配时的操作:拒绝(不记录) -->
<onMismatch>DENY</onMismatch>
</filter>
</appender>
<!-- 异步输出 -->
<appender name="ASYNC-INFO" class="ch.qos.logback.classic.AsyncAppender">
<!-- 不丢失日志.默认的,如果队列的80%已满,则会丢弃TRACT、DEBUG、INFO级别的日志 -->
<discardingThreshold>0</discardingThreshold>
<!-- 更改默认的队列的深度,该值会影响性能.默认值为256 -->
<queueSize>512</queueSize>
<!-- 添加附加的appender,最多只能添加一个 -->
<appender-ref ref="file_info"/>
</appender>
<appender name="ASYNC-ERROR" class="ch.qos.logback.classic.AsyncAppender">
<!-- 不丢失日志.默认的,如果队列的80%已满,则会丢弃TRACT、DEBUG、INFO级别的日志 -->
<discardingThreshold>0</discardingThreshold>
<!-- 更改默认的队列的深度,该值会影响性能.默认值为256 -->
<queueSize>512</queueSize>
<!-- 添加附加的appender,最多只能添加一个 -->
<appender-ref ref="file_error"/>
</appender>
<!-- 日志总开关 -->
<root level="INFO">
<appender-ref ref="CONSOLE" />
<appender-ref ref="ASYNC-INFO" />
<appender-ref ref="ASYNC-ERROR" />
</root>
<!-- 日志过滤 -->
<logger name="org.apache.catalina.startup.DigesterFactory" level="ERROR"/>
<logger name="org.apache.catalina.util.LifecycleBase" level="ERROR"/>
<logger name="org.apache.coyote.http11.Http11NioProtocol" level="WARN"/>
<logger name="org.apache.sshd.common.util.SecurityUtils" level="WARN"/>
<logger name="org.apache.tomcat.util.net.NioSelectorPool" level="WARN"/>
<logger name="org.eclipse.jetty.util.component.AbstractLifeCycle" level="ERROR"/>
<logger name="org.hibernate.validator.internal.util.Version" level="WARN"/>
</configuration>
1.9 除了Zipkin的链路跟踪
除了Zipkin还有链路跟踪:
-
CAT
:是一个更综合性的平台,提供的监控功能最全面,国内几个大厂生产也都在使用。但研发进度及版本更新相对较慢。实时应用监控平台,
研发团队:吴其敏老师团队(携程)尤勇老师团队(大众点评)
系统层:cpu,mem,disk,load
等
应用层:JVM
,链路,web调用,方法代码执行次数耗时等
业务层:业务KPI数据(手动埋点)
消息传输:netty
支持的存储:本地文件,hdfs
,Mysql
-
Zipkin
:由Twitter
开源,调用链分析工具,基于spring-cloud-sleuth得到广泛使用,非常轻量,使用部署简单。
系统层:无
应用层:链路,接口执行次数耗时等
业务层:无
消息传输:消息队列,http
支持的存储:Mysql
,Elasticsearch
,Cassandra
-
Skywalking
:专注于链路和性能监控,国产开源,埋点无侵入,UI功能较强。能够加入Apache孵化器,设计思想及代码得到一定认可,后期应该也会有更多的发展空间及研发人员投入。目前使用厂商最多。版本更新较快。
系统层:cpu,mem,disk
等
应用层:JVM,链路,方法执行次数耗时等
业务层:无
消息传输:gRpc
支持的存储:Elasticsearch
,Mysql
,TiDB
,H2
,Sharding Sphere
-
Pinpoint
:专注于链路和性能监控,韩国研发团队开源,埋点无侵入,UI功能较强,但毕竟是小团队,不知道会不会一直维护着,目前版本仍在更新中
系统层:cpu,mem,disk等
应用层:JVM,链路,方法执行次数耗时等
业务层:无
消息传输:thrift
支持的存储:Hbase