分布式服务跟踪 - Sleuth

一、Spring Cloud Sleuth简介

现今互联网环境中，微服务系统越来越庞大、复杂，微服务间的调用关系也越加复杂。往往一个请求，会出发系统后台多个微服务协同工作得到最终结果，那么在复杂的调用网中，任何一个服务出现问题，都会导致整体功能出错。
这时，微服务跟踪工具应运而生，其在整体微服务应用中能跟踪一个请求的整体流程。并提供数据采集，数据传输，数据存储，数据分析，数据可视化功能。微服务跟踪工具捕获的这些跟踪数据，就能构建出整个微服务调用链视图，为调试和监控微服务系统提供帮助。
Spring Cloud Sleuth就是这样的微服务跟踪工具。其特点为：
提供链路追踪：通过Sleuth可以很清楚的看到一次请求经过哪些服务调用，可以方便理清服务间调用关系。
性能分析、数据分析、优化链路：通过Sleuth可以很方便的看出每个采样请求的耗时，分析出哪些服务调用比较耗时，可以为微服务系统的调优提供数据支撑。
可视化视图：可以提供可视化视图，更直观的查看采样数据。

二、使用ELK收集服务跟踪数据

Sleuth是基于logback实现数据跟踪的。在默认情况下，Sleuth是基于日志向控制台输出跟踪内容。不利于管理，统计，查看，分析。在控制台中输出跟踪内容会严重影响系统性能。如果将跟踪数据记录在logback对应的日志文件中，也有问题：logback是分散的，是集成在每个服务应用中的，那么日志文件也是分散的， 也不利于跟踪信息的查看，管理，分析。
所以Sleuth提供了集中式的跟踪数据存储方案。可以使用ELK来实现logback跟踪信息的收集，存储。实质上是使用logstash来做数据的收集，用ElasticSearch做数据的存储，使用Kibana做数据的视图显示。
使用ELK收集跟踪数据，必须依赖Logback日志工具，也就是必须提供logback.xml配置文件，并且日志级别建议调整为DEBUG。
使用ELK收集跟踪数据结构图

1. Logstash配置

Logstash中的配置内容：定义在$logstash_home/config/xxx.conf。本案例中的配置文件命名为：log_to_es.conf。内容如下：其中input用于定义logstash对外提供的输入配置；output用于定义logstash接收数据后的输出配置，ElasticSearch相关配置根据具体环境定义。

        # For detail structure of this file
        # Set: https://www.elastic.co/guide/en/logstash/current/configuration-file-structure.html
        input {
          # For detail config for log4j as input,
          # See: https://www.elastic.co/guide/en/logstash/current/plugins-inputs-log4j.html
          tcp {
            mode => "server" # logstash在整体环境中处于的角色
            host => "192.168.1.148" # logstash安装所在位置
            port => 9250 # logstash对外监听的服务端口
          }
        }
        filter {
          #Only matched data are send to output.
        }
        output {
          # For detail config for elasticsearch as output,
          # See: https://www.elastic.co/guide/en/logstash/current/plugins-outputs-elasticsearch.html
          elasticsearch {
            action => "index"          # 向ES中的什么位置输出
            hosts  => "192.168.1.148:9200"   #ElasticSearch host, can be array.
            index  => "applog"         # ES中保存跟踪数据的索引名.
          }
        }

配置文件配置完毕后，重新启动Logstash，启动命令为：
$logstash_home/bin/logstash -f config/log_to_es.conf
上述命令是让Logstash启动的时候加载自定义配置文件，提供输入及输出配置。

2. 在ElasticSearch中创建需要的索引

命令如下：根据具体环境定义settings相关内容，当前案例省略，使用默认配置。

PUT applog
{
	  “settings”:{
	    “number_of_shards” : 1,
	    “number_of_replicas” : 1
	}
}

3. 修改所有需要采集跟踪信息的应用

增加Sleuth相关依赖

		<!-- sleuth启动器依赖 -->
		<dependency>
			<groupId>org.springframework.cloud</groupId>
			<artifactId>spring-cloud-starter-sleuth</artifactId>
		</dependency>
		<!-- logstash相关依赖，用于应用中的Sleuth将采集的跟踪数据发送给logstash使用 -->
		<dependency>
			<groupId>net.logstash.logback</groupId>
			<artifactId>logstash-logback-encoder</artifactId>
			<version>5.0</version>
		</dependency>

提供logback.xml配置文件，并定义logstash相关输出配置：其中logstash的输出目的地destination需要根据具体环境配置。如果使用logstash集群，destination内的地址使用逗号‘,’分割。

<?xml version="1.0" encoding="UTF-8"?>
<!--该日志将日志级别不同的log信息保存到不同的文件中 -->
<configuration>
	<include resource="org/springframework/boot/logging/logback/defaults.xml" />

	<springProperty scope="context" name="springAppName"
		source="spring.application.name" />

	<!-- 日志在工程中的输出位置 -->
	<property name="LOG_FILE" value="${BUILD_FOLDER:-build}/${springAppName}" />

	<!-- 控制台的日志输出样式 -->
	<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} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}" />

	<!-- 控制台输出 -->
	<appender name="console" class="ch.qos.logback.core.ConsoleAppender">
		<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
			<level>INFO</level>
		</filter>
		<!-- 日志输出编码 -->
		<encoder>
			<pattern>${CONSOLE_LOG_PATTERN}</pattern>
			<charset>utf8</charset>
		</encoder>
	</appender>

	<!-- 为logstash输出的JSON格式的Appender -->
	<appender name="logstash"
		class="net.logstash.logback.appender.LogstashTcpSocketAppender">
		<destination>192.168.1.148:9250</destination>
		<!-- 日志输出编码 -->
		<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:-}",
						"exportable": "%X{X-Span-Export:-}",
						"pid": "${PID:-}",
						"thread": "%thread",
						"class": "%logger{40}",
						"rest": "%message"
						}
					</pattern>
				</pattern>
			</providers>
		</encoder>
	</appender>

	<!-- 日志输出级别 -->
	<root level="DEBUG">
		<appender-ref ref="console" />
		<appender-ref ref="logstash" />
	</root>
</configuration>

上述所有步骤操作完毕后，使用ELK实现跟踪数据收集的案例就改造完毕了，可以启动并观察ElasticSearch中对应索引的内容。

4. 跟踪数据查看及含义介绍

查看跟踪数据的时候，可以根据索引中字段message搜索，主要观察的是包含Trace相关内容的数据，数据格式如下:

{
  "@timestamp":"2018-11-21T14:26:31.264+00:00", #时间戳
  "severity":"DEBUG", # 收集的跟踪数据日志级别
  "service":"e-book-user-provider", # 当前跟踪的服务名称
  "trace":"c82b2d23e6c3245b", # 一个请求的完整链路唯一标记
  "span":"95b7128dec20f57f", # 一个请求中某一执行节点的唯一标记
  "exportable":"false",
  "pid":"8144",
  "thread":"http-nio-9002-exec-8",
  "class":"o.s.c.sleuth.instrument.web.TraceFilter",
  "rest":
    "Parent span is [
      Trace: c82b2d23e6c3245b,  #一个请求的完整链路唯一标记
      Span: 95b7128dec20f57f,  # 当前执行节点的唯一标记
      Parent: c82b2d23e6c3245b,  # 当前执行节点的上级执行节点的唯一标记
      exportable:false
    ]"
}

使用图形简单解释上述数据