SpringCloud之Sleuth全链路日志跟踪

1 Sleuth链路跟踪

本篇文章所涉及到的demo练习 使用的 springcloud 2021.0.3+ springboot2.6.8

1.1 分布式系统面临的问题

在微服务框架中，一个由客户端发起的请求在后端系统中会经过多个不同的的服务节点调用来协同产生最后的请求结果，每一个次请求都会形成一条复杂的分布式服务调用链路，链路中的任何一环出现高延时或错误都会引起整个请求最后的失败。

1.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）。

下图显示了 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

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启动：

然后访问：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的日志：

故意制造异常
在消费服务的接口上故意制造异常：

@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>

 

  
 

点击了解Logback文件解析

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

参考文章：https://mp.weixin.qq.com/s/tNZz58aRNuqz7E6CnwCkmQ

转载：https://blog.csdn.net/u012060033/article/details/128498158