Spring Cloud Sleuth service link tracking

Posted by Rebelrebellious on Thu, 20 Feb 2020 09:49:41 +0100

Zipkin service tracking principle

Create some tracking identifiers (tracking ID, spanId, parentId), and finally build a request process tree. When each business system calls each other, it will pass specific tracking messages to Zipkin. After Zipkin collects tracking information, it will aggregate, process, store, display, etc. users can easily obtain network delay, call link, system dependency, etc. through the web UI.

transport function: collect the spans of the services tracked, convert them to zipkin common Span, and then transfer these spans to the storage layer

collector will verify, store and index the data (span) of a trace (Cassandra / es search / memory)

Zipkin basic concept & core data structure
  • Annotation (purpose: to locate the beginning and end of a request. cs/sr/ss/cr contains additional information, such as time point):
    • cs: Client Start, indicating the start of a span request initiated by the client
    • sr: Server Receive, indicating that the server receives the request
    • ss: Server Send, indicating that the server completes processing and sends the result to the client
    • cr: Client Received, indicating the end of a span when the client obtains the information returned by the server. When the annotation is recorded, the RPC is also considered completed. Client call time = cr CS, server processing time = SR SS.
  • Span: a request (including a set of annotations and binaryannotations); it is a basic unit of work. A link call (which can be RPC, DB, etc. without specific restrictions) creates a span, which is identified by a 64 bit ID.
    • Span also has other data, such as description information, timestamp, annotation tag information of key value pair, parent ID, etc., in which parent ID can represent the source of span call link, which is generally understood as one-time request information
  • Trace: a span set similar to the tree structure, which represents a call link. There is a unique identification through traceId (the global tracking ID, which is the entry point of tracking. According to the needs, it determines where to generate traceId), spanId (request tracking ID, such as primary rpc), and parentId (last time The request tracking ID is used to concatenate the previous and subsequent requests. The collected span will be aggregated into a tree to provide an overall process of request.

The whole description: in a Trace, every call of each service is a basic unit of work, just like every tree node in the above figure, which is called span. Each span has an id as the unique identifier. Similarly, each Trace will generate a traceId in span as the tracking identifier. In addition, a parentId will be used to indicate the initiator of this call (that is, the span id of the initiator). When span has the above three identifications, it can clearly comb and concatenate multiple spans, and finally conclude a complete tracking link.

Code practice

No storage, just console

The source code of this article is: git@github.com : chengcheng222e/springcloud-learn.git welcome to fork.

/Users/chenyuan/Workspaces/Github/springcloud-learn/eureka-server

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

application.properties

spring.application.name=eureka-server
server.port=8001
eureka.instance.hostname=localhost
eureka.client.service-url.defaultZone=http://${eureka.instance.hostname}:${server.port}/eureka
eureka.client.register-with-eureka=false
eureka.client.fetch-registry=false

/Users/chenyuan/Workspaces/Github/springcloud-learn/zipkin-server

package com.allei;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.cloud.netflix.eureka.EnableEurekaClient;
import zipkin.server.internal.EnableZipkinServer;

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

application.properties

spring.application.name=zipkin-server
server.port=10000

eureka.client.serviceUrl.defaultZone=http://localhost:8001/eureka/

zipkin.instance.hostname=localhost
spring.zipkin.base-url=http://${zipkin.instance.hostname}:${server.port}/

spring.sleuth.enabled=false
spring.sleuth.sampler.probability=1.0
spring.sleuth.hystrix.strategy.enabled=true

spring.main.allow-bean-definition-overriding=true

/Users/chenyuan/Workspaces/Github/springcloud-learn/trace-a

package com.allei;

import java.util.concurrent.TimeUnit;

import lombok.extern.slf4j.Slf4j;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.cloud.client.discovery.EnableDiscoveryClient;
import org.springframework.cloud.client.loadbalancer.LoadBalanced;
import org.springframework.context.annotation.Bean;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RequestMethod;
import org.springframework.web.bind.annotation.RestController;
import org.springframework.web.client.RestTemplate;

@RestController
@EnableDiscoveryClient
@SpringBootApplication
@Slf4j
public class TraceAApplication {

	@Bean
	@LoadBalanced
	RestTemplate restTemplate() {
		return new RestTemplate();
	}

	@RequestMapping(value = "/trace-a", method = RequestMethod.GET)
	public String trace() throws InterruptedException {
		log.info("call trace-a----->");
		TimeUnit.SECONDS.sleep(1l);
		return restTemplate().getForEntity("http://trace-b/trace-b", String.class).getBody();
	}

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

application.properties

spring.application.name=trace-a
server.port=10001

eureka.client.serviceUrl.defaultZone=http://localhost:8001/eureka/

spring.zipkin.base-url=http://localhost:10000
spring.sleuth.sampler.percentage=1
# log trace detail
logging.level.org.springframework.web.servlet.DispatcherServlet=DEBUG

/Users/chenyuan/Workspaces/Github/springcloud-learn/trace-b

package com.allei;

import java.util.concurrent.TimeUnit;

import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang.math.RandomUtils;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.cloud.client.discovery.EnableDiscoveryClient;
import org.springframework.cloud.client.loadbalancer.LoadBalanced;
import org.springframework.context.annotation.Bean;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RequestMethod;
import org.springframework.web.bind.annotation.RestController;
import org.springframework.web.client.RestTemplate;

@RestController
@EnableDiscoveryClient
@SpringBootApplication
@Slf4j
public class TraceBApplication {

    @Bean
    @LoadBalanced
    RestTemplate restTemplate() {
        return new RestTemplate();
    }

    @RequestMapping(value = "/trace-b", method = RequestMethod.GET)
    public String trace() throws InterruptedException {
        log.info("call trace-b----->");
		TimeUnit.SECONDS.sleep(RandomUtils.nextInt(2));
        return restTemplate().getForEntity("http://trace-c/trace-c", String.class).getBody();
    }

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

application.properties

spring.application.name=trace-b
server.port=10002

eureka.client.serviceUrl.defaultZone=http://localhost:8001/eureka/

spring.zipkin.base-url=http://localhost:10000

spring.sleuth.sampler.percentage=1

# log trace detail
logging.level.org.springframework.web.servlet.DispatcherServlet=DEBUG

/Users/chenyuan/Workspaces/Github/springcloud-learn/trace-c

package com.allei;

import java.util.concurrent.TimeUnit;

import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang.math.RandomUtils;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.cloud.client.discovery.EnableDiscoveryClient;
import org.springframework.cloud.client.loadbalancer.LoadBalanced;
import org.springframework.context.annotation.Bean;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RequestMethod;
import org.springframework.web.bind.annotation.RestController;
import org.springframework.web.client.RestTemplate;

@RestController
@EnableDiscoveryClient
@SpringBootApplication
@Slf4j
public class TraceCApplication {
    @Bean
    @LoadBalanced
    RestTemplate restTemplate() {
        return new RestTemplate();
    }

    @RequestMapping(value = "/trace-c", method = RequestMethod.GET)
    public String trace() throws InterruptedException {
        log.info("call trace-c----->");
        TimeUnit.SECONDS.sleep(RandomUtils.nextInt(2));
        return "hello trace";
    }

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

application.properties

spring.application.name=trace-c
server.port=10003
eureka.client.serviceUrl.defaultZone=http://localhost:8001/eureka/
spring.zipkin.base-url=http://localhost:10000
spring.sleuth.sampler.percentage=1
# log trace detail
logging.level.org.springframework.web.servlet.DispatcherServlet=DEBUG

Start all the services, and then let's go to the registration center to see how the services are started.

http://localhost:8001/eureka/

We trigger a service from the trace-a service:

Check the log

/Users / Chenyuan / workspaces / GitHub / springcloud learn / trace-a log

2020-01-10 12:04:51.226 DEBUG [trace-a,c8df468b969a0917,c8df468b969a0917,false] 2626 --- [io-10001-exec-1] o.s.web.servlet.DispatcherServlet        : GET "/trace-a", parameters={}
2020-01-10 12:04:51.240  INFO [trace-a,c8df468b969a0917,c8df468b969a0917,false] 2626 --- [io-10001-exec-1] com.allei.TraceAApplication              : call trace-a----->
2020-01-10 12:04:52.528  INFO [trace-a,c8df468b969a0917,a4c77f10471bb209,false] 2626 --- [io-10001-exec-1] c.netflix.config.ChainedDynamicProperty  : Flipping property: trace-b.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2020-01-10 12:04:52.558  INFO [trace-a,c8df468b969a0917,a4c77f10471bb209,false] 2626 --- [io-10001-exec-1] c.n.u.concurrent.ShutdownEnabledTimer    : Shutdown hook installed for: NFLoadBalancer-PingTimer-trace-b
2020-01-10 12:04:52.558  INFO [trace-a,c8df468b969a0917,a4c77f10471bb209,false] 2626 --- [io-10001-exec-1] c.netflix.loadbalancer.BaseLoadBalancer  : Client: trace-b instantiated a LoadBalancer: DynamicServerListLoadBalancer:{NFLoadBalancer:name=trace-b,current list of Servers=[],Load balancer stats=Zone stats: {},Server stats: []}ServerList:null
2020-01-10 12:04:52.564  INFO [trace-a,c8df468b969a0917,a4c77f10471bb209,false] 2626 --- [io-10001-exec-1] c.n.l.DynamicServerListLoadBalancer      : Using serverListUpdater PollingServerListUpdater
2020-01-10 12:04:52.588  INFO [trace-a,c8df468b969a0917,a4c77f10471bb209,false] 2626 --- [io-10001-exec-1] c.netflix.config.ChainedDynamicProperty  : Flipping property: trace-b.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2020-01-10 12:04:52.590  INFO [trace-a,c8df468b969a0917,a4c77f10471bb209,false] 2626 --- [io-10001-exec-1] c.n.l.DynamicServerListLoadBalancer      : DynamicServerListLoadBalancer for client trace-b initialized: DynamicServerListLoadBalancer:{NFLoadBalancer:name=trace-b,current list of Servers=[172.18.232.69:10002],Load balancer stats=Zone stats: {defaultzone=[Zone:defaultzone;	Instance count:1;	Active connections count: 0;	Circuit breaker tripped count: 0;	Active connections per server: 0.0;]
},Server stats: [[Server:172.18.232.69:10002;	Zone:defaultZone;	Total Requests:0;	Successive connection failure:0;	Total blackout seconds:0;	Last connection made:Thu Jan 01 08:00:00 CST 1970;	First connection made: Thu Jan 01 08:00:00 CST 1970;	Active Connections:0;	total failure count in last (1000) msecs:0;	average resp time:0.0;	90 percentile resp time:0.0;	95 percentile resp time:0.0;	min resp time:0.0;	max resp time:0.0;	stddev resp time:0.0]
]}ServerList:org.springframework.cloud.netflix.ribbon.eureka.DomainExtractingServerList@128e37fa
2020-01-10 12:04:53.573  INFO [trace-a,,,] 2626 --- [erListUpdater-0] c.netflix.config.ChainedDynamicProperty  : Flipping property: trace-b.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2020-01-10 12:04:54.397 DEBUG [trace-a,c8df468b969a0917,c8df468b969a0917,false] 2626 --- [io-10001-exec-1] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
2020-01-10 12:04:54.731 DEBUG [trace-a,4eb7430157ffd40f,4eb7430157ffd40f,false] 2626 --- [io-10001-exec-2] o.s.web.servlet.DispatcherServlet        : GET "/favicon.ico", parameters={}
2020-01-10 12:04:54.749 DEBUG [trace-a,4eb7430157ffd40f,4eb7430157ffd40f,false] 2626 --- [io-10001-exec-2] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
2020-01-10 12:06:16.665  INFO [trace-a,,,] 2626 --- [trap-executor-0] c.n.d.s.r.aws.ConfigClusterResolver      : Resolving eureka endpoints via configuration
2020-01-10 12:11:16.661  INFO [trace-a,,,] 2626 --- [trap-executor-0] c.n.d.s.r.aws.ConfigClusterResolver      : Resolving eureka endpoints via configuration

/Users / Chenyuan / workspaces / GitHub / springcloud learn / trace-b log

2020-01-10 12:04:52.733 DEBUG [trace-b,c8df468b969a0917,a4c77f10471bb209,false] 2862 --- [io-10002-exec-1] o.s.web.servlet.DispatcherServlet        : GET "/trace-b", parameters={}
2020-01-10 12:04:52.752  INFO [trace-b,c8df468b969a0917,a4c77f10471bb209,false] 2862 --- [io-10002-exec-1] com.allei.TraceBApplication              : call trace-b----->
2020-01-10 12:04:53.062  INFO [trace-b,c8df468b969a0917,e9651abffa9bf1d2,false] 2862 --- [io-10002-exec-1] c.netflix.config.ChainedDynamicProperty  : Flipping property: trace-c.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2020-01-10 12:04:53.108  INFO [trace-b,c8df468b969a0917,e9651abffa9bf1d2,false] 2862 --- [io-10002-exec-1] c.n.u.concurrent.ShutdownEnabledTimer    : Shutdown hook installed for: NFLoadBalancer-PingTimer-trace-c
2020-01-10 12:04:53.108  INFO [trace-b,c8df468b969a0917,e9651abffa9bf1d2,false] 2862 --- [io-10002-exec-1] c.netflix.loadbalancer.BaseLoadBalancer  : Client: trace-c instantiated a LoadBalancer: DynamicServerListLoadBalancer:{NFLoadBalancer:name=trace-c,current list of Servers=[],Load balancer stats=Zone stats: {},Server stats: []}ServerList:null
2020-01-10 12:04:53.116  INFO [trace-b,c8df468b969a0917,e9651abffa9bf1d2,false] 2862 --- [io-10002-exec-1] c.n.l.DynamicServerListLoadBalancer      : Using serverListUpdater PollingServerListUpdater
2020-01-10 12:04:53.146  INFO [trace-b,c8df468b969a0917,e9651abffa9bf1d2,false] 2862 --- [io-10002-exec-1] c.netflix.config.ChainedDynamicProperty  : Flipping property: trace-c.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2020-01-10 12:04:53.148  INFO [trace-b,c8df468b969a0917,e9651abffa9bf1d2,false] 2862 --- [io-10002-exec-1] c.n.l.DynamicServerListLoadBalancer      : DynamicServerListLoadBalancer for client trace-c initialized: DynamicServerListLoadBalancer:{NFLoadBalancer:name=trace-c,current list of Servers=[172.18.232.69:10003],Load balancer stats=Zone stats: {defaultzone=[Zone:defaultzone;	Instance count:1;	Active connections count: 0;	Circuit breaker tripped count: 0;	Active connections per server: 0.0;]
},Server stats: [[Server:172.18.232.69:10003;	Zone:defaultZone;	Total Requests:0;	Successive connection failure:0;	Total blackout seconds:0;	Last connection made:Thu Jan 01 08:00:00 CST 1970;	First connection made: Thu Jan 01 08:00:00 CST 1970;	Active Connections:0;	total failure count in last (1000) msecs:0;	average resp time:0.0;	90 percentile resp time:0.0;	95 percentile resp time:0.0;	min resp time:0.0;	max resp time:0.0;	stddev resp time:0.0]
]}ServerList:org.springframework.cloud.netflix.ribbon.eureka.DomainExtractingServerList@4e144ec0
2020-01-10 12:04:54.124  INFO [trace-b,,,] 2862 --- [erListUpdater-0] c.netflix.config.ChainedDynamicProperty  : Flipping property: trace-c.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647
2020-01-10 12:04:54.374 DEBUG [trace-b,c8df468b969a0917,a4c77f10471bb209,false] 2862 --- [io-10002-exec-1] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
2020-01-10 12:06:57.545  INFO [trace-b,,,] 2862 --- [trap-executor-0] c.n.d.s.r.aws.ConfigClusterResolver      : Resolving eureka endpoints via configuration
2020-01-10 12:11:57.541  INFO [trace-b,,,] 2862 --- [trap-executor-0] c.n.d.s.r.aws.ConfigClusterResolver      : Resolving eureka endpoints via configuration

/Users / Chenyuan / workspaces / GitHub / springcloud learn / trace-c log

2020-01-10 12:04:53.306 DEBUG [trace-c,c8df468b969a0917,e9651abffa9bf1d2,false] 3211 --- [io-10003-exec-1] o.s.web.servlet.DispatcherServlet        : GET "/trace-c", parameters={}
2020-01-10 12:04:53.320  INFO [trace-c,c8df468b969a0917,e9651abffa9bf1d2,false] 3211 --- [io-10003-exec-1] com.allei.TraceCApplication              : call trace-c----->
2020-01-10 12:04:54.346 DEBUG [trace-c,c8df468b969a0917,e9651abffa9bf1d2,false] 3211 --- [io-10003-exec-1] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
2020-01-10 12:08:09.576  INFO [trace-c,,,] 3211 --- [trap-executor-0] c.n.d.s.r.aws.ConfigClusterResolver      : Resolving eureka endpoints via configuration
2020-01-10 12:13:09.572  INFO [trace-c,,,] 3211 --- [trap-executor-0] c.n.d.s.r.aws.ConfigClusterResolver      : Resolving eureka endpoints via configuration

Reference address

If you like my article, you can pay attention to the personal subscription number. Welcome to leave a message and communicate at any time.

Topics: Programming Spring github AWS Java