服务跟踪Sleuth

发表于 更新于 分类于 ， ， 阅读次数： Changyan： 本文字数： 3.2k 阅读时长 ≈ 11 分钟

引言

在微服务架构下，服务之间的调用关系越来越复杂，通过 Zuul 转发到具体的业务接 ，一个接口中会涉及多个微服务的交互，只要其中某个服务出现问题，整个请求都将失败。这个时候我们要想快速定位到问题所在，就需要用到链路跟踪了。每个请求都是一条完整的调用链，通过调用链我们可以清楚地知道这个请求经过了哪些服务，在哪个服务上耗时多长时间，进而达到快速定位问题的目的。

为了解决上面提到的问题， Spring Cloud Sleuth为我们提供了完整的解决方案。本章我们将学习如何使用 Spring Cloud Sleuth来构建分布式链路跟踪功能。

——《spring cloud 微服务 入门、进阶与实战》第197页

Sleuth 官网：https://spring.io/projects/spring-cloud-sleuth#overview

spring cloud 集成 Sleuth

  • 给调用链中所有服务加上依赖
1
2
3
4
<dependency>
  <groupId>org.springframework.cloud</groupId>
  <artifactId>spring-cloud-starter-sleuth</artifactId>
</dependency>
  • 代码中打印日志：
1
logger.info("method call/hello be called.....");
  • 调用接口：A 服务 调用 B 服务的接口
1
2
3
4
# A 服务日志 ：
2020-05-13 15:33:04.439  INFO [spring-cloud-hystrix,f764aae854c0d690,f764aae854c0d690,false] 20316 --- [nio-8087-exec-1] com.study.controller.Controller          : method call/hello be called.....
# B 服务日志 :
2020-05-13 15:33:04.704  INFO [eureka-client-service,f764aae854c0d690,6569e6c4685070be,false] 22164 --- [nio-8081-exec-1] c.s.s.controller.UserController          : method be called....

注意服务日志中的这段：

[spring-cloud-hystrix,f764aae854c0d690,f764aae854c0d690,false]

这里会记录每个服务的 名称 ，编号（trace），编号（span），是否导入数据到 Zipki 中，A 服务调用 B 服务，那么 A 服务的编号（span）就对应 B 服务的编号（trace）。以此来跟踪整个调用链路。

整合 LogStash

首先

格式化日志的输出格式为 json

pom 添加依赖：

1
2
3
4
5
6
<!-- 输出 Json 格式日志 -->
<dependency>
  <groupId>net.logstash.logback</groupId>
  <artifactId>logstash-logback-encoder</artifactId>
  <version>5.2</version>
</dependency>

在 resources 下建立 logback-spring.xml

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    ​
    <springProperty scope="context" name="springAppName" source="spring.application.name"/>

    <!-- Example for logging into the build folder of your project -->
<!--    <property name="LOG_FILE" value="/Users/yinjihuan/Downloads/sleuth-user-service.log"/>​-->
    <property name="LOG_FILE" value="D:/IdeaProjects/spring-cloud-study/springcloud-hystrix/sleuth-user-service.log" />
    <!-- You can override this to have a custom pattern -->
    <property name="CONSOLE_LOG_PATTERN"
              value="%clr(%d{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}"/>

    <!-- Appender to log to console -->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <!-- Minimum logging level to be presented in the console logs-->
            <level>INFO</level>
        </filter>
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>utf8</charset>
        </encoder>
    </appender>

    <!-- Appender to log to file -->​
    <appender name="flatfile" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_FILE}</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE}.%d{yyyy-MM-dd}</fileNamePattern>
            <maxHistory>7</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>utf8</charset>
        </encoder>
    </appender>
    ​
    <!-- Appender to log to file in a JSON format-->
    <appender name="logstash" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_FILE}.json</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE}.json.%d{yyyy-MM-dd}.gz</fileNamePattern>
            <maxHistory>7</maxHistory>
        </rollingPolicy>
        <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
            <providers>
                <timestamp>
                    <timeZone>UTC</timeZone>
                </timestamp>
                <pattern>
                    <pattern>
                        {
                        "severity": "%level",
                        "service": "${springAppName:-}",
                        "trace": "%X{X-B3-TraceId:-}",
                        "span": "%X{X-B3-SpanId:-}",
                        "parent": "%X{X-B3-ParentSpanId:-}",
                        "exportable": "%X{X-Span-Export:-}",
                        "pid": "${PID:-}",
                        "thread": "%thread",
                        "class": "%logger{40}",
                        "rest": "%message"
                        }
                    </pattern>
                </pattern>
            </providers>
        </encoder>
    </appender>
    ​
    <root level="INFO">
        <appender-ref ref="console"/>
        <!-- uncomment this to have also JSON logs-->
        <appender-ref ref="logstash"/>
        <appender-ref ref="flatfile"/>
    </root>
</configuration>

请求接口让日志文件中记录下调用链的信息。

使用ELK查询服务调用链

ELK是Elasticsearch、Logstash、Kibana三大开源框架首字母大写简称。市面上也被成为Elastic Stack。其中 Elasticsearch 是一个基于Lucene、分布式、通过 Restful 方式进行交互的近实时搜索平台框架。像类似百度、谷歌这种大数据全文搜索引擎的场景都可以使用 Elasticsearch 作为底层支持框架，可见Elasticsearch 提供的搜索能力确实强大,市面上很多时候我们简称 Elasticsearch 为 ES 。Logstash是 ELK的中央数据流引擎，用于从不同目标（文件/数据存储/MQ）收集的不同格式数据，经过过滤后支持输出到不同目的地（文件/MQ/redis/elasticsearch/kafka等）。Kibana可以将elasticsearch的数据通过友好的页面展示出来，提供实时分析的功能。

—— laizhiy的简书

下载 elasticsearch 和 kibana 地址：https://www.elastic.co/cn/start

下载 logstash 地址：https://www.elastic.co/cn/downloads/logstash

下载后解压：注意不要放在中文目录下，不然 logstash 会启动报错

image-20200513205655908

  • 在 elasticsearch 解压的 bin 目录下双击执行 elasticsearch.bat 。后在浏览器访问 http://localhost:9200/ 出现类似如下内容 说明启动成功！
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
{
  "name" : "DESKTOP-SAUA6M1",
  "cluster_name" : "elasticsearch",
  "cluster_uuid" : "M-ZSPWU8SZyFqB2DWvqX2g",
  "version" : {
    "number" : "7.6.2",
    "build_flavor" : "default",
    "build_type" : "zip",
    "build_hash" : "ef48eb35cf30adf4db14086e8aabd07ef6fb113f",
    "build_date" : "2020-03-26T06:34:37.794943Z",
    "build_snapshot" : false,
    "lucene_version" : "8.4.0",
    "minimum_wire_compatibility_version" : "6.8.0",
    "minimum_index_compatibility_version" : "6.0.0-beta1"
  },
  "tagline" : "You Know, for Search"
}
  • 编辑 logstash 目录 -> config -> logstash-sample.conf 文件

意思就是 读取 input 的内容 通过 output 发送到 elasticsearch 。我这里 是把 springcloud-eureka-server-consumer，springcloud-eureka-server-provider 作为集群，提供给 springcloud-hystrix 来调用。所以我这里读取三个 json 日志文件。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
input {
	file {
		path => ["D:/IdeaProjects/spring-cloud-study/springcloud-eureka-server-consumer/sleuth-user-service.log.json",
		"D:/IdeaProjects/spring-cloud-study/springcloud-eureka-server-provider/sleuth-user-service.log.json",
		"D:/IdeaProjects/spring-cloud-study/springcloud-hystrix/sleuth-user-service.log.json"]

	start_position => "beginning"
    
    #设置编码
    codec => json {charset => "UTF-8"}

	}
}
output {
  elasticsearch {
    hosts => ["http://localhost:9200"]
    index => "sleuth"
    #类型
    document_type => "json_index"

    #user => "elastic"
    #password => "changeme"
  }
}
  • 启动 logstash 采集数据 发送到 elasticsearch

在 logstash 目录 -> bin 目录下 通过 gitbash (或者其它 bash 客户端 ) 执行

1
2
wuzhiyong@DESKTOP-SAUA6M1 MINGW64 /d/ELK/logstash-7.6.2/bin
$ ./logstash -f ../config/logstash-sample.conf

如果出现异常： invalid byte sequence in US-ASCII ，请检查你路径中不能有中文。

一切正常 会提示 Successfully started

  • 配置与启动 kibana

修改 kibana-7.6.2-windows-x86_64 -> config 下的 kibana.yml 。解开下列属性的注释 使其生效并保存。

1
2
3
4
5
6
server.port: 5601
server.host: "localhost"
server.name: localhost
elasticsearch.hosts: ["http://localhost:9200"]
kibana.index: ".kibana"
kibana.defaultAppId: "home"

双击 kibana-7.6.2-windows-x86_64 下 bin 目录下的 kibana.bat

如果成功会有类似提示：

1
2
log   [09:58:01.360] [info][listening] Server running at http://localhost:5601
log   [09:58:01.529] [info][server][Kibana][http] http server running at http://localhost:5601

检索数据

打开 http://localhost:5601/

填写个 sleuth 点击 next step

image-20200513180017941

选择 I don`t want to …. 点击 create index pattern

image-20200513180113059

会出现下面这个界面

image-20200513180142097

看图：

image-20200513213835958

点击 1 就会来到这个 检索的界面。

2 的输入框输入检索的内容

3 添加需要展示的 列

4 检索按钮

5 展示框 展示数据

通过检索就可以很清楚的知道，调用链什么时间经过了哪些服务，调用了什么接口。

整合 Zipkin

Zipkin 是 twitter 开发的一个致力于收集所有服务的监控数据的分布式跟踪系统。

gitHub 地址：https://github.com/openzipkin/zipkin

快速使用

image-20200513233208638

下到本地后执行 ：java -jar zipkin ….

spring cloud 项目添加依赖

1
2
3
4
<dependency>
  <groupId>org.springframework.cloud</groupId>
  <artifactId>spring-cloud-starter-zipkin</artifactId>
</dependency>

properties 中配置

1
2
3
4
# 配置 zipkin server 地址
spring.zipkin.base-url=http://127.0.0.1:9411
# zipkin 抽样比例
spring.sleuth.sampler.probability=1.0

重启项目

控制台中复制 trace id

image-20200513233747139

浏览器访问：http://localhost:9411/zipkin/

image-20200513233407667

把 trace id 复制到 图中 1 按回车

即可查到调用链

image-20200513234422669

异步任务线程池定义

在 《spring cloud 微服务 入门、进阶与实战》书中说。我们用 @Async 开启一个异步任务后，Sleuth 会为这个调用新创建一个 span. 如果你自定义了异步任务的线程池，会导致无法新创建一个 Span 。这需要使用 Sleuth 提供的 LazyTraceAsyncTaskExecutor 来包装：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
//自定义线程池配置   部分代码		

		@Autowired
    BeanFactory beanFactory;

    @Override
    public Executor getAsyncExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(config.getCorePoolSize());
        executor.setMaxPoolSize(config.getMaxPoolSize());
        executor.setQueueCapacity(config.getQueueCapacity());
        executor.setKeepAliveSeconds(config.getKeepAliveSeconds());
        executor.setThreadNamePrefix(config.getThreadNamePrefix());
        /**
         * 线程池拒绝策略：如果不配置并超过了负荷会造成溢出
         * AbortPolicy:直接抛出异常  会丢弃任务
         * CallerRunsPolicy 先由主线程执行当前任务，下个任务继续交给线程池来执行
         */
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        executor.initialize();
      //使用 LazyTraceAsyncTaskExecutor 进行包装。
        return new LazyTraceAsyncTaskExecutor(this.beanFactory,executor);
//        return executor;
    }

测试用例：

1
2
3
4
5
6
7
8
@GetMapping("/call/hello")
public String cellHello(){
    logger.info("method call/hello be called.....");
    myservice.saveLog();//异步方法
    myservice.saveLog2();//
    return userRemoteClient.hello();
}

已包装：

image-20200514111125122

未包装：

image-20200514110947974

TracingFilter 自定义

TracingFilter 是负责处理请求和响应的组件，我们可以通过注册自定义的 TracingFilter 实例来实现一些扩展性的需求。下例将演示如何给请求添加自定义的标记以及将请求 ID 添加到响应头返回给客户端。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
@Component
@Order(TraceWebServletAutoConfiguration.TRACING_FILTER_ORDER + 1)
class MyFilter extends GenericFilterBean {

    private final Tracer tracer;

    MyFilter(Tracer tracer) {
        this.tracer = tracer;
    }

    @Override
    public void doFilter(ServletRequest request, ServletResponse response,
                         FilterChain chain) throws IOException, ServletException {
        Span currentSpan = this.tracer.currentSpan();
        if (currentSpan == null) {
            chain.doFilter(request, response);
            return;
        }
        ((HttpServletResponse) response).addHeader("ZIPKIN-TRACE-ID",
                currentSpan.context().traceIdString());
        currentSpan.tag("custom", "tag");
        chain.doFilter(request, response);
    }
}

浏览器调试请求：

image-20200514111811873

可在响应头中看到 trace-id 这对调试问题非常有帮助。

监控本地方法

异步和远程调用都会开启一个 span ,如果想监控本地方法，可采用埋点的方式监控本地方法，也就是开启一个新的 span

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
    @Autowired
    Tracer tracer;
    @Async
    public void saveLog() {
        logger.info("异步线程执行");

    }
//	  方法一  使用注解
//    @NewSpan(name = "saveLog2")
    public void saveLog2() {
      //   方法二   使用 tracer 对象
        ScopedSpan span = tracer.startScopedSpan("saveLog2");
        try {
            Thread.sleep(2000);
        } catch (Exception | Error e) {
            span.error(e);
        } finally {
            span.finish();
        }
    }

用 RabbitMq 代替 http 发送调用链数据

虽然有基于采样的收集方式，但是数据的发送采用 Http 还是对性能有影响。如果 Zipkin 的服务端重启或挂掉了，那么将丢失部分采集数据。为了解决这个问题，我们将集成 RabbitMq 来发送采集数据，利用消息队列来提高发送性能，保证数据不会丢。

安装 RabbitMq 环境

RabbitMq 依赖于 Erlang 所以先安装 Erlang

  • 安装 Erlang

下载：https://www.erlang.org/downloads

  • 安装 rabbitmq

下载：https://www.rabbitmq.com/install-windows-manual.html

安装与配置环境变量参考：https://www.cnblogs.com/nongzihong/p/11578255.html

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
# 查看 rabbitmq 状态
D:\Program Files\rabbitmq_server-3.8.3\sbin>rabbitmqctl status
Error: unable to perform an operation on node 'rabbit@DESKTOP-SAUA6M1'. Please see diagnostics information and suggestions below.

# enable rabbitmq_management
###
D:\Program Files\rabbitmq_server-3.8.3\sbin>rabbitmq-plugins.bat enable rabbitmq_management
Enabling plugins on node rabbit@DESKTOP-SAUA6M1:
rabbitmq_management
The following plugins have been configured:
  rabbitmq_management
  rabbitmq_management_agent
  rabbitmq_web_dispatch
Applying plugin configuration to rabbit@DESKTOP-SAUA6M1...
The following plugins have been enabled:
  rabbitmq_management
  rabbitmq_management_agent
  rabbitmq_web_dispatch

set 3 plugins.
Offline change; changes will take effect at broker restart.


# 再启动 rabbitmq
D:\Program Files\rabbitmq_server-3.8.3\sbin>rabbitmq-server.bat

  ##  ##      RabbitMQ 3.8.3
  ##  ##
  ##########  Copyright (c) 2007-2020 Pivotal Software, Inc.
  ######  ##
  ##########  Licensed under the MPL 1.1. Website: https://rabbitmq.com

  Doc guides: https://rabbitmq.com/documentation.html
  Support:    https://rabbitmq.com/contact.html
  Tutorials:  https://rabbitmq.com/getstarted.html
  Monitoring: https://rabbitmq.com/monitoring.html

  Logs: C:/Users/wuzhiyong/AppData/Roaming/RabbitMQ/log/rabbit@DESKTOP-SAUA6M1.log
        C:/Users/wuzhiyong/AppData/Roaming/RabbitMQ/log/rabbit@DESKTOP-SAUA6M1_upgrade.log

  Config file(s): (none)

  Starting broker... completed with 3 plugins.

访问：http://localhost:15672/

用户名：guest 密码：guest

image-20200514144246611

spring cloud 项目的配置

把所有项目都配上：

pom:

1
2
3
4
<dependency>
  <groupId>org.springframework.amqp</groupId>
  <artifactId>spring-rabbit</artifactId>
</dependency>

properties

1
2
3
4
5
6
7
8
# 注释掉 
#spring.zipkin.base-url=http://127.0.0.1:9411

# 增加
spring.zipkin.sender.type=RABBIT
spring.rabbitmq.addresses=amqp:localhost:15672/
spring.rabbitmq.username=guest
spring.rabbitmq.password=guest

启动 zinkin : 带上 rabbit 的参数

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
wuzhiyong@DESKTOP-SAUA6M1 MINGW64 /d/Zipkin
$ java -DRABBIT_ADDRESSES=127.0.0.1:5672 -DRABBIT_USER=guest -DRABBIT_PASSWORD=guest -jar zipkin-server-2.21.1-exec.jar

                  oo
                 oooo
                oooooo
               oooooooo
              oooooooooo
             oooooooooooo
           ooooooo  ooooooo
          oooooo     ooooooo
         oooooo       ooooooo
        oooooo   o  o   oooooo
       oooooo   oo  oo   oooooo
     ooooooo  oooo  oooo  ooooooo
    oooooo   ooooo  ooooo  ooooooo
   oooooo   oooooo  oooooo  ooooooo
  oooooooo      oo  oo      oooooooo
  ooooooooooooo oo  oo ooooooooooooo
      oooooooooooo  oooooooooooo
          oooooooo  oooooooo
              oooo  oooo

     ________ ____  _  _____ _   _
    |__  /_ _|  _ \| |/ /_ _| \ | |
      / / | || |_) | ' / | ||  \| |
     / /_ | ||  __/| . \ | || |\  |
    |____|___|_|   |_|\_\___|_| \_|

:: version 2.21.1 :: commit c30ffc5 ::

2020-05-14 15:51:16.549  INFO 416 --- [           main] z.s.ZipkinServer                         : Starting ZipkinServer on DESKTOP-SAUA6M1 with PID 416 (D:\Zipkin\zipkin-server-2.21.1-exec.jar started by wuzhiyong in D:\Zipkin)
2020-05-14 15:51:16.552  INFO 416 --- [           main] z.s.ZipkinServer                         : The following profiles are active: shared
2020-05-14 15:51:17.400  INFO 416 --- [           main] c.l.a.c.u.SystemInfo                     : Hostname: desktop-saua6m1 (from 'hostname' command)
2020-05-14 15:51:18.100  INFO 416 --- [oss-http-*:9411] c.l.a.s.Server                           : Serving HTTP at /0:0:0:0:0:0:0:0:9411 - http://127.0.0.1:9411/
2020-05-14 15:51:18.100  INFO 416 --- [           main] c.l.a.s.ArmeriaAutoConfiguration         : Armeria server started at ports: {/0:0:0:0:0:0:0:0:9411=ServerPort(/0:0:0:0:0:0:0:0:9411, [http])}
2020-05-14 15:51:18.115  INFO 416 --- [           main] z.s.ZipkinServer                         : Started ZipkinServer in 2.126 seconds (JVM running for 3.133)
查看

rabbitMq

image-20200514160521203

请求接口后再从 zipkin 中查看某个调用链：

image-20200514160606857

用 Elasticsearch 存储调用链数据

目前收集的数据都是存在 Zipkin 服务的内存中，服务一重启这些数据就没了，我们需要将这些数据持久化。实际使用中数据量可能会比较大，所以一般数据库并不是很好的选择，可以选择 ES 来存储数据，ES 在搜索方面有先天的优势

启动 ES

启动 zipkin ，带上 ES 的参数。

1
2
wuzhiyong@DESKTOP-SAUA6M1 MINGW64 /d/Zipkin
$ java -DSTORAGE_TYPE=elasticsearch -DES_HOST=http://127.0.0.1:9200 -DRABBIT_ADDRESSES=127.0.0.1:5672 -DRABBIT_USER=guest -DRABBIT_PASSWORD=guest -jar zipkin-server-2.21.1-exec.jar

访问几次接口生成几条条用链数据：

在 zipkin 中查看。

image-20200514162719215

重启 zipkin 用刚才的 trace id 查询。查到了说明数据被保存了。

验证数据是否存到了 ES

我们再访问 ES 的接口 查找索引：http://localhost:9200/_cat/indices

image-20200514163051852

有了 zipkin 前缀的索引。说明 zipkin 的数据保存到了ES里

通过 kibana 也可以看到这条索引：

image-20200514163858862

在 kibana 中创建对应的 index pattern

image-20200514164331054

然后就可以通过 trace id 搜素到了：

image-20200514164652907

参考：《spring cloud 微服务 入门、进阶与实战》