微服务追踪:Spring Cloud Sleuth

要重新更新文章了,边学习边更。
参考文章:Tracing In Microservices With Spring Cloud Sleuth

微服务增长时,开发者遇到的一个问题就是如何追踪从一个服务到另一个服务的请求。想要知道请求是如何在微服务中穿行是一件困难的事,尤其是你对微服务内部如何调用还不是很深入的时候。

Spring Cloud Sleuth就是为了帮助解决这个问题,它在微服务的logging引入唯一性的id让你知道一个请求如何从一个微服务到另一个微服务。

Spring Cloud Sleuth添加2种类型id到你的日志中,一个是trace id 另一个是span id,span id是最基本单元,例如发送一个http请求,一个trace id包含多个span id,类似树结构。trace id在各个服务交互中保持一致。让我们来看一下如何用sleuth来追求请求的简单例子。

首先建立一个spring boot项目添加spring-cloud-starter-slueth依赖。最好给你的程序设置一个名字通过 spring.application.name,这个名字会显示在追踪信息中。

现在让我们添加一些打印日志

@SpringBootApplication
@RestController
public class SleuthSampleApplication {
    public static void main(String[] args) {
        SpringApplication.run(SleuthSampleApplication.class, args);
    }

    @RequestMapping("/")
    public String home() {
        LOG.log(Level.INFO, "you called home");
    return "Hello World";
    }
}

启动项目,访问http://localhost:8080你会看到 Hello World.同时会打印出日志

2016-06-15 16:55:56.334  INFO [slueth-sample,44462edc42f2ae73,44462edc42f2ae73,false] 13978 --- [nio-8080-exec-1] com.example.SleuthSampleApplication      : calling home

可以看到日志中多了 [slueth-sample,44462edc42f2ae73,44462edc42f2ae73,false]。这些有什么含义呢?首先第一部分是application name(yml中通过spring.application.name设置的)。第二部分是trace id。第三个部分是span id。最后的false代表span是否开放给zipkin(后面会讲到)

除了添加追踪信息到日志之外,Sleuth还提供了一些其他的帮助。记住我们的真正问题不是在单个服务中辨认log而是追踪跨越多个服务的请求链。微服务之间一般用rest api同步交互或者通过消息中间件异步交互。Seluth都提供了支持 下面的例子我们看一下rest api如何追踪的。

这个简单例子我们通过RestTemplate来调用自己。我们修改一下代码

private static final Logger LOG = Logger.getLogger(SleuthSampleApplication.class.getName());

@Autowired
private RestTemplate restTemplate;

public static void main(String[] args) {
SpringApplication.run(SleuthSampleApplication.class, args);
}

@Bean
public RestTemplate getRestTemplate() {
    return new RestTemplate();
}

@RequestMapping("/")
public String home() {
LOG.log(Level.INFO, "you called home");
    return "Hello World";
}

@RequestMapping("/callhome")
public String callHome() {
LOG.log(Level.INFO, "calling home");
    return restTemplate.getForObject("http://localhost:8080", String.class);
}

看到上面的代码你第一件事可能会问:为什么要使用RestTemplate? 这是必须的因为Sleuth会在request的headers里面添加trace id和span id.

启动项目 访问 http://localhost:8080/callhome 你会看到2条日志

2016-06-17 16:12:36.902  INFO [slueth-sample,432943172b958030,432943172b958030,false] 12157 --- [nio-8080-exec-2] com.example.SleuthSampleApplication      : calling home
2016-06-17 16:12:36.940  INFO [slueth-sample,432943172b958030,b4d88156bc6a49ec,false] 12157 --- [nio-8080-exec-3] com.example.SleuthSampleApplication      : you called home

注意2条日志的trace id是一样的但是span id不一样。trace id就是你能够追踪一个请求从一个服务到另一个服务的原因所在。span id不同是因为我们有2次不同的“工作单元”,即2个请求

如果你打开浏览器debug工具看一下 /callhome请求的headers你会发现2个headers在response中

X-B3-SpanId: fbf39ca6e571f294
X-B3-TraceId: fbf39ca6e571f294

这些headers就是Sleuth能够在微服务中追踪请求的原因。

如果你在用Feign,追踪信息同样会添加到这些请求中。同样的Zuul也会trace和span headers通过代理转发给其他服务。

Zipkin

日志中的这些附加信息确实很好但是想要理解所有信息非常麻烦。用类似ELK之类的工具进行收集和分析会帮助很大。这样通过trace id 你就可以非常简单搜索到收集的日志并查看http请求是如何从一个微服务到另一个的。

然而你要是想看时间信息呢?你当然可以自己计算但是非常痛苦。好消息是已经有一个叫Zipkin的项目可以帮助我们了。Sleuth会把追踪信息发送到你指定的zipken服务当你依赖了 spring-cloud-sleuth-zipkin。默认Sleuth会假定你的zipkin服务运行在 http://localhost:9411。 地址可以通过spring.zipkin.baseUrl进行配置。

我们可以用zipkin收集上面例子的追踪信息。创建一个新的spring boot项目依赖zipin ui和zipkin server。设置端口为9411。启动项目浏览器输入 http://localhost:9411 你会看到 zipkin ui

ui

让我们上面的例子开启发送追踪信息到zipkin server。打开pom添加

<dependency>
    <groupId>org.springframework.cloud</groupId>
    <artifactId>spring-cloud-sleuth-zipkin</artifactId>
</dependency>

此外我们需要告诉我们的应用程序需要发送哪些信息给zipkin。因为是个demo,所以让我们发送全部通过创建一个AlwaysSampler

@Bean
public AlwaysSampler defaultSampler() {
  return new AlwaysSampler();
}

添加完重新启动。输入 http://localhost:8080/callhome 你会发现日志的 export flag 从 false 变成了 true.

2016-06-20 09:03:44.939  INFO [slueth-sample,380c24fd1e5f89df,380c24fd1e5f89df,true] 19263 --- [nio-8080-exec-1] com.example.SleuthSampleApplication      : calling home
2016-06-20 09:03:44.966  INFO [slueth-sample,380c24fd1e5f89df,fc50a65582b7b845,true] 19263 --- [nio-8080-exec-2] com.example.SleuthSampleApplication      : you called home

这说明追踪信息发送到了 zipkin server。 打开 zipkin ui 页面 确保日期范围正确然后点击find taces 。你会看到 /callhome 的追踪信息 。点击会给你显示详细包含时间信息。

image.png
image.png

如果你想要了解更多,建议去了解官网文档。

推荐阅读更多精彩内容

  • Spring Cloud为开发人员提供了快速构建分布式系统中一些常见模式的工具(例如配置管理,服务发现,断路器,智...
    卡卡罗2017阅读 121,131评论 16 134
  • 普元推出DevOps系列课程,5分钟秒懂一个知识点,戳“阅读原文”充电5分钟,掌握黑科技。 转载本文需注明出处:微...
    EAII企业架构创新研究院阅读 2,805评论 0 0
  • 这是我第一次在“简述”上开始记录我的生活,我也不知道写点什么、无以记述,那就从关于我是谁、做什么、能做什么说起吧。...
    小状陈阅读 81评论 0 1
  • 世界真的很小,可以将我们联系在一起,在各个角落里,我们有着不知名的相遇。 在寂静,老式的街道旁的一家杂货店,在所有...
    言叶未至阅读 203评论 0 2
  • 选择器的特殊性:特殊性的值表示为四个部分 ,比如 0 0 0 0 对于选择器中给定的各个ID属性值,加0 1 0 ...
    风色透明阅读 118评论 0 1