Spring Cloud（Finchley.RELEASE版本）微服务学习实践：6.1全链路追踪-Sleuth

环境：

jdk1.8；spring boot2.0.3；spring cloud（Finchley.RELEASE版本）;Maven3.3

摘要说明：

全链路追踪：一个微服务系统，服务之间的调用往往是很复杂的，一个消费者往往需要调用多个服务提供者才能得到结果，即几乎每一个前端请求都会形成一条复杂的分布式服务调用链路，在每条链路中任何一个依赖服务出现延迟过高或错误的时候都有可能引起请求最后的失败。这时候对于每个请求全链路调用的跟踪就变得越来越重要，通过实现对请求调用的跟踪可以帮助我们快速的发现错误根源以及监控分析每条请求链路上的性能瓶颈等好处。

Spring Cloud Sleuth：Spring Cloud Sleuth为Spring Cloud实施分布式跟踪解决方案，大量借用Dapper，Zipkin和HTrace。对于大多数用户来说，Sleuth应该是不可见的，并且所有与外部系统的交互都应该自动进行检测。您可以简单地在日志中捕获数据，或者将数据发送到远程收集器服务。更多参考：官网

步骤：

1.创建sleuthRibbon（sleuth服务消费者）和sleuthEurekaDiscovery（服务提供至）子项目

首先模仿ribbon和eurekaDiscovery复制sleuthRibbon（sleuth服务消费者）和sleuthEurekaDiscovery（服务提供至）子项目；其中application.properties分别为：

sleuthEurekaDiscovery：

#配置服务名称及端口
spring.application.name=sleuth-eureka-client
server.port=2101

#将服务注册到注册中心
eureka.client.serviceUrl.defaultZone=http://localhost:1001/eureka/

#——————————————添加健康检查配置——————————————
# 该配置指示eureka客户端需要向eureka服务器发送心跳的频率  (Spring Cloud默认该配置是 30s)
eureka.instance.lease-renewal-interval-in-seconds=1

# 该配置指示eureka服务器在接收到最后一个心跳之后等待的时间，然后才能从列表中删除此实例 (Spring Cloud默认该配置是 90s)
eureka.instance.lease-expiration-duration-in-seconds=10
           

sleuthRibbon：

#配置服务及端口
spring.application.name=sleuth-ribbon-consumer
server.port=3101
#注册到注册中心
eureka.client.serviceUrl.defaultZone=http://localhost:1001/eureka/

#从eureka服务器注册表中获取注册信息的时间间隔（s），默认为30秒
eureka.client.registry-fetch-interval-seconds=5
           

2.开发一个服务调用及日志打印

我们在上述的两个项目中开发下述两个接口：

sleuthEurekaDiscovery（TestLogController）：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
public class TestLogController {
	protected final static Logger logger = LoggerFactory.getLogger(TestLogController.class);

	@GetMapping("/infoLog-1")
	public String infoLog() {
		logger.info("------infoLog-1------");
		return "infoLog";
	}
}
           

sleuthRibbon（TestLogController）：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;
import org.springframework.web.client.RestTemplate;

@RestController
public class TestLogController {
	protected final static Logger logger = LoggerFactory.getLogger(TestLogController.class);
	@Autowired
	RestTemplate restTemplate;

	@GetMapping("/infoLog-2")
	public String infoLog() {
		logger.info("------infoLog-2------");
		return restTemplate.getForEntity("http://SLEUTH-EUREKA-CLIENT/infoLog-1", String.class).getBody();
	}
}
           

先后启动

服务注册中心（eurekaServer）：eureka-server（1001）

服务提供者（sleuthEurekaDiscovery）：sleuth-eureka-client（2101）

服务消费者（sleuthRibbon）：sleuth-ribbon-consumer（3101）

访问http://localhost:3101/infoLog-2；先后分别看到日志

2018-07-02 11:25:31.593  INFO 11376 --- [nio-3101-exec-5] c.t.s.s.controller.TestLogController     : ------infoLog-2------
           

2018-07-02 11:25:31.596  INFO 13444 --- [nio-2101-exec-6] c.t.s.s.controller.TestLogController     : ------infoLog-1------
           

3.添加Spring Cloud Sleuth

我们分别在上述两个子项目的pom.xml中添加Spring Cloud Sleuth的依赖：

再重复上面的操作查看日志，会出现[sleuth-ribbon-consumer,1681af8931e6f1b7,1681af8931e6f1b7,false]分别表示：应用名称，traceId，spanId，表示是否要将该信息输出到Zipkin等服务中来收集和展示；

其中spanId表示一个工作单元，如一个HTTP请求

下面两个链路的日志前一个的spanId和下一个的traceId一致达到一个全链路；

2018-07-02 11:35:45.773  INFO [sleuth-ribbon-consumer,1681af8931e6f1b7,1681af8931e6f1b7,false] 8168 --- [nio-3101-exec-1] c.t.s.s.controller.TestLogController     : ------infoLog-2------
           

2018-07-02 11:35:46.057  INFO [sleuth-eureka-client,1681af8931e6f1b7,df4315b11efce95d,false] 9080 --- [io-2101-exec-10] c.t.s.s.controller.TestLogController     : ------infoLog-1------
           

将日志级别设置为DEBUG（logging.level.org.springframework.web.servlet.DispatcherServlet=DEBUG）看到的日志更多；

2018-07-02 13:59:22.063 DEBUG [sleuth-ribbon-consumer,a62adda9e1031c9f,a62adda9e1031c9f,false] 8508 --- [nio-3101-exec-5] o.s.web.servlet.DispatcherServlet        : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling
2018-07-02 13:59:22.065 DEBUG [sleuth-ribbon-consumer,a62adda9e1031c9f,a62adda9e1031c9f,false] 8508 --- [nio-3101-exec-5] o.s.web.servlet.DispatcherServlet        : Successfully completed request
2018-07-02 13:59:22.175 DEBUG [sleuth-ribbon-consumer,61006e3b87325039,61006e3b87325039,false] 8508 --- [nio-3101-exec-5] o.s.web.servlet.DispatcherServlet        : DispatcherServlet with name 'dispatcherServlet' processing GET request for [/favicon.ico]
2018-07-02 13:59:22.184 DEBUG [sleuth-ribbon-consumer,61006e3b87325039,61006e3b87325039,false] 8508 --- [nio-3101-exec-5] o.s.web.servlet.DispatcherServlet        : Last-Modified value for [/favicon.ico] is: -1
2018-07-02 13:59:22.427 DEBUG [sleuth-ribbon-consumer,61006e3b87325039,61006e3b87325039,false] 8508 --- [nio-3101-exec-5] o.s.web.servlet.DispatcherServlet        : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling
2018-07-02 13:59:22.428 DEBUG [sleuth-ribbon-consumer,61006e3b87325039,61006e3b87325039,false] 8508 --- [nio-3101-exec-5] o.s.web.servlet.DispatcherServlet        : Successfully completed request
           

2018-07-02 13:59:21.863 DEBUG [sleuth-eureka-client,a62adda9e1031c9f,dee896f4cdf6b927,false] 10544 --- [nio-2101-exec-1] o.s.web.servlet.DispatcherServlet        : DispatcherServlet with name 'dispatcherServlet' processing GET request for [/infoLog-1]
2018-07-02 13:59:21.877 DEBUG [sleuth-eureka-client,a62adda9e1031c9f,dee896f4cdf6b927,false] 10544 --- [nio-2101-exec-1] o.s.web.servlet.DispatcherServlet        : Last-Modified value for [/infoLog-1] is: -1
2018-07-02 13:59:21.912  INFO [sleuth-eureka-client,a62adda9e1031c9f,dee896f4cdf6b927,false] 10544 --- [nio-2101-exec-1] c.t.s.s.controller.TestLogController     : ------infoLog-1------
2018-07-02 13:59:21.995 DEBUG [sleuth-eureka-client,a62adda9e1031c9f,dee896f4cdf6b927,false] 10544 --- [nio-2101-exec-1] o.s.web.servlet.DispatcherServlet        : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling
2018-07-02 13:59:21.999 DEBUG [sleuth-eureka-client,a62adda9e1031c9f,dee896f4cdf6b927,false] 10544 --- [nio-2101-exec-1] o.s.web.servlet.DispatcherServlet        : Successfully completed request
           

4.源码地址

github地址：https://github.com/cc6688211/springCloud.git