Spring Cloud (八)：服务调用追踪 sleuth & zipkin

随着微服务的增多，一个请求可能会涉及到很多个微服务，如何追踪跨多个服务的请求，就成了一个需要解决的问题

Spring Cloud Sleuth 主要功能就是在分布式系统中提供追踪解决方案

它的做法是在日志里面添加 Trace Id 和 Span Id，其中 Trace Id 在所有 service 中都是一样的，而 Span Id 是在两个 service 之间一样的，HTTP 请求响应会带上 Trace Id 和 Span Id，如下图

例子代码如下，这里实现三个 service

pom 文件都添加 sleuth dependency

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

query service

    @RequestMapping("/query")
    public String query(@RequestParam(value = "id", required = true) String id){
    	log.info("Handling query"); 
        String forObject = restTemplate.getForObject("http://sleuth-product-service/product/" + id, String.class);
        return forObject;
    }

product service

    @GetMapping("/product/{id}")
    public String product(@PathVariable("id") String id) {
    	log.info("Handling product");
    	String forObject = restTemplate.getForObject("http://sleuth-store-service/store/price/" + id, String.class);
        return "price of product " + id + " is " + forObject;
    }

store service

    @GetMapping("/store/price/{id}")
    public String price(@PathVariable("id") String id) {
    	log.info("Handling price");
        return "100";
    }

访问 query service 的 query 接口，可以看到各个 service 的日志如下

query service 日志

2021-01-06 20:51:01.503  INFO [spring-cloud-sleuth-query,f1c9c9fde13787fe,f1c9c9fde13787fe,true] 7936 --- [nio-8501-exec-2] com.example.demo.Controller.Controller   : Handling query
2021-01-06 20:51:01.741  INFO [spring-cloud-sleuth-query,f1c9c9fde13787fe,290b6c1f34796c56,true] 7936 --- [nio-8501-exec-2] c.netflix.config.ChainedDynamicProperty  : Flipping property: sleuth-product-service.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2021-01-06 20:51:01.848  INFO [spring-cloud-sleuth-query,f1c9c9fde13787fe,290b6c1f34796c56,true] 7936 --- [nio-8501-exec-2] c.n.u.concurrent.ShutdownEnabledTimer    : Shutdown hook installed for: NFLoadBalancer-PingTimer-sleuth-product-service
2021-01-06 20:51:01.850  INFO [spring-cloud-sleuth-query,f1c9c9fde13787fe,290b6c1f34796c56,true] 7936 --- [nio-8501-exec-2] c.netflix.loadbalancer.BaseLoadBalancer  : Client: sleuth-product-service instantiated a LoadBalancer: DynamicServerListLoadBalancer:{NFLoadBalancer:name=sleuth-product-service,current list of Servers=[],Load balancer stats=Zone stats: {},Server stats: []}ServerList:null
2021-01-06 20:51:01.882  INFO [spring-cloud-sleuth-query,f1c9c9fde13787fe,290b6c1f34796c56,true] 7936 --- [nio-8501-exec-2] c.n.l.DynamicServerListLoadBalancer      : Using serverListUpdater PollingServerListUpdater
2021-01-06 20:51:01.968  INFO [spring-cloud-sleuth-query,f1c9c9fde13787fe,290b6c1f34796c56,true] 7936 --- [nio-8501-exec-2] c.netflix.config.ChainedDynamicProperty  : Flipping property: sleuth-product-service.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2021-01-06 20:51:01.976  INFO [spring-cloud-sleuth-query,f1c9c9fde13787fe,290b6c1f34796c56,true] 7936 --- [nio-8501-exec-2] c.n.l.DynamicServerListLoadBalancer      : DynamicServerListLoadBalancer for client sleuth-product-service initialized: DynamicServerListLoadBalancer:{NFLoadBalancer:name=sleuth-product-service,current list of Servers=[192.168.0.100:8506],Load balancer stats=Zone stats: {unknown=[Zone:unknown;	Instance count:1;	Active connections count: 0;	Circuit breaker tripped count: 0;	Active connections per server: 0.0;]

product service 日志

2021-01-06 20:51:02.084  INFO [spring-cloud-sleuth-product,f1c9c9fde13787fe,290b6c1f34796c56,true] 4340 --- [nio-8506-exec-3] com.example.demo.Controller.Controller   : Handling product
2021-01-06 20:51:02.497  INFO [spring-cloud-sleuth-product,f1c9c9fde13787fe,b731c9c2d5031dfc,true] 4340 --- [nio-8506-exec-3] c.netflix.config.ChainedDynamicProperty  : Flipping property: sleuth-store-service.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2021-01-06 20:51:02.569  INFO [spring-cloud-sleuth-product,f1c9c9fde13787fe,b731c9c2d5031dfc,true] 4340 --- [nio-8506-exec-3] c.n.u.concurrent.ShutdownEnabledTimer    : Shutdown hook installed for: NFLoadBalancer-PingTimer-sleuth-store-service
2021-01-06 20:51:02.570  INFO [spring-cloud-sleuth-product,f1c9c9fde13787fe,b731c9c2d5031dfc,true] 4340 --- [nio-8506-exec-3] c.netflix.loadbalancer.BaseLoadBalancer  : Client: sleuth-store-service instantiated a LoadBalancer: DynamicServerListLoadBalancer:{NFLoadBalancer:name=sleuth-store-service,current list of Servers=[],Load balancer stats=Zone stats: {},Server stats: []}ServerList:null
2021-01-06 20:51:02.590  INFO [spring-cloud-sleuth-product,f1c9c9fde13787fe,b731c9c2d5031dfc,true] 4340 --- [nio-8506-exec-3] c.n.l.DynamicServerListLoadBalancer      : Using serverListUpdater PollingServerListUpdater
2021-01-06 20:51:02.684  INFO [spring-cloud-sleuth-product,f1c9c9fde13787fe,b731c9c2d5031dfc,true] 4340 --- [nio-8506-exec-3] c.netflix.config.ChainedDynamicProperty  : Flipping property: sleuth-store-service.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2021-01-06 20:51:02.692  INFO [spring-cloud-sleuth-product,f1c9c9fde13787fe,b731c9c2d5031dfc,true] 4340 --- [nio-8506-exec-3] c.n.l.DynamicServerListLoadBalancer      : DynamicServerListLoadBalancer for client sleuth-store-service initialized: DynamicServerListLoadBalancer:{NFLoadBalancer:name=sleuth-store-service,current list of Servers=[192.168.0.100:8503],Load balancer stats=Zone stats: {unknown=[Zone:unknown;	Instance count:1;	Active connections count: 0;	Circuit breaker tripped count: 0;	Active connections per server: 0.0;]

store service 日志

2021-01-06 20:51:02.786  INFO [spring-cloud-sleuth-store,f1c9c9fde13787fe,b731c9c2d5031dfc,true] 8124 --- [io-8503-exec-10] com.example.demo.Controller.Controller   : Handling price

可以看到，第一个 ID，也就是 Trace ID，是 f1c9c9fde13787fe，在所有日志中都是一样的，而第二个 ID，也就是 Span ID，只在两个 service 之间通信的时候一样，比如 product service 发请求的时候是 b731c9c2d5031dfc，store service 收到请求的时候也是 b731c9c2d5031dfc

如果想更直观的看各个 service 的依赖，可以和 zipkin 结合起来

先安装 zipkin https://github.com/openzipkin/zipkin

curl -sSL https://zipkin.io/quickstart.sh | bash -s
java -jar zipkin.jar

所有 service 都添加 dependency

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

添加配置

spring:
  zipkin:
    base-url: http://localhost:9411/
    service:
      name: sleuth-store

重新启动 service，访问 query，登录 http://localhost:9411/ 可以看到