[Spring Cloud] Spring Cloud Sleuth usage record

preface

Spring Cloud Sleuth components mainly play the role of error location and troubleshooting and link performance analysis under the Spring Cloud microservice system. This paper mainly illustrates some usage scenarios of Spring Cloud Sleuth

Official illustration:

Popular understanding, Tracer Represents the entire complete request, and the corresponding is unique traceId
Span express Tracer Multiple call links under the corresponding spanId
 Borrow official illustration:

logback configuration

Spring Cloud Sleuth provides a logback configuration by default. We can also provide our own logback-spring.xml to modify the log format and expand the log storage method. Here is a best practice example

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <springProperty scope="context" name="springAppName" source="spring.application.name"/>

    <property name="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} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}"/>

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${PATTERN}</pattern>
            <charset>utf8</charset>
        </encoder>
    </appender>

    <appender name="app"
              class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>app.log</file>
        <encoder>
            <pattern>${PATTERN}</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>app.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <maxHistory>7</maxHistory>
            <maxFileSize>50MB</maxFileSize>
            <totalSizeCap>10GB</totalSizeCap>
        </rollingPolicy>

        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>info</level>
        </filter>
    </appender>

    <appender name="error"
              class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>error.log</file>
        <encoder>
            <pattern>${PATTERN}</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>error.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <maxHistory>7</maxHistory>
            <maxFileSize>50MB</maxFileSize>
            <totalSizeCap>10GB</totalSizeCap>
        </rollingPolicy>

        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>error</level>
        </filter>
    </appender>

    <root level="info">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="app"/>
        <appender-ref ref="error"/>
    </root>
</configuration>
  • Define log output partten and record applicationName traceId spanId to facilitate log location, analysis and troubleshooting
  • In the example, the info log is recorded in Console and app.log, and the error log is recorded in Console and error.log

Use in WEB Environment

After integrating the Spring Cloud Sleuth dependency, corresponding tracers and spans will be automatically created for each endpoint

Guess by interceptor TracingFilter Implementation: generate corresponding instances and place them in ThreadLocal In,
be similar to HttpServletRequest JdbcTemplate etc.
If I guess wrong, when I didn't say

Interceptor processing

In order to make the generated traceId spanId visible to the front end (mainly traceId), so as to locate the log for troubleshooting, we need to pass the corresponding traceId generated by the request to the front end as agreed. Here is an example of placing the traceId in the response header based on the interceptor

@Component
public class TraceFilter implements Filter {

	@Autowired
	Tracer tracer;

	private static final String TRACE_ID = "traceId";

	@Override
	public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {

		Optional.ofNullable(response)
				.map(rep -> (HttpServletResponse) rep)
				.ifPresent(rep -> rep.addHeader(TRACE_ID, Optional.ofNullable(tracer)
						.map(t -> t.currentSpan())
						.map(span -> span.context())
						.map(context -> context.traceId())
						.orElse("")));
		chain.doFilter(request, response);
	}
}
  • Tracer is the corresponding tracer instance, which can be used to obtain Span traceId and other information
  • rep.addHeader puts traceId information in the response header, or you can add other information yourself

Common example

	@RequestMapping(value = "/", method = RequestMethod.GET)
	public void test() {
		testService.test();
	}

	------- TestService

	public void test(String... args) {
		logger.info("run");
	}

Post startup access http://ip:port , record the corresponding log:

2021-09-13 15:47:55.956  INFO [trace,b7b57a40295f489c,b7b57a40295f489c] 34549 --- [nio-8080-exec-1] c.xsn.demo.sc.trace.config.TestService   : run

-- [trace,b7b57a40295f489c,b7b57a40295f489c] Sequential correspondence applicationName traceId spanId

The front page corresponds to the response header information:

Troubleshooting example

	@RequestMapping(value = "/testerror", method = RequestMethod.GET)
	public void error() {
		try {
			int i = 1 / 0;
		} catch (Exception e) {
			logger.error(e.getMessage());
		}
	}

Post startup access http://ip:port/testerror , if an error is found on the page, get the traceId information from the response header and give it to the back-end for troubleshooting:

Locate the error log information in error.log to further troubleshoot the problem:

summary

With the help of section log, manual printing and other means, you can record the key information of the calling link, and then directly locate the log for troubleshooting through traceId

Asynchronous environment

The above examples are the most common usage scenarios, and the whole call link is synchronous. In some scenarios, there is a business need for the main thread to call the sub threads. In fact, they should be under the same Tracer (Span doesn't matter)

Ordinary Executor ExecutorService and ScheduledExecutorService naturally do not provide this capability, but Spring Cloud Sleuth provides corresponding LazyTraceExecutor TraceableExecutorService and TraceableScheduledExecutorService. Meanwhile, Spring Cloud Sleuth will also generate corresponding tracers for asynchronous tasks based on @ Async annotation

TraceableExecutorService example

	@RequestMapping(value = "/traceAsync", method = RequestMethod.GET)
	public void traceAsync() {
		testService.traceAsync();
	}

	-------- TestService

	public void traceAsync() {
		logger.info("sup - trace async");

		TraceableExecutorService traceableExecutorService
				= new TraceableExecutorService(beanFactory, new ThreadPoolExecutor(
				2, 4, 1, TimeUnit.SECONDS, new LinkedBlockingQueue<>()
		));
		traceableExecutorService.execute(() -> logger.info("sub - trace async"));
	}

The asynchronous task is called by ThreadPoolExecutor wrapped in TraceableExecutorService to create and transfer tracers. The results are as follows:

As shown in the figure, the main thread call link and the sub thread call link are under different spans of the same Tracer

@Async example

	@RequestMapping(value = "/async", method = RequestMethod.GET)
	public void async() {
		logger.info("sup - async");
		testService.doAsync();
	}

	-------- TestService with @EnableAsync

	@Async
	public void doAsync() {
		logger.info("sub - async");
	}

The subtask is called by the Spring asynchronous framework, @ Async, and Spring Cloud Sleuth implements the creation and delivery of its Tracer

The results are as follows:

HttpClient call

Here is only an example of RestTemplate. The call of Spring Cloud Sleuth to RestTemplate also realizes the creation and transmission of Tracer. Of course, the premise is that RestTemplate is managed by container (no additional configuration is required, just introduce Spring Cloud Sleuth dependency, Spring yyds)

RestTemplate example

	@Bean
	public RestTemplate restTemplate(RestTemplateBuilder restTemplateBuilder) {
		return restTemplateBuilder.build();
	}

	@RequestMapping(value = "/restTemplateCall", method = RequestMethod.GET)
	public void restTemplateCall() {
		testService.restTemplateCall();
	}

	@RequestMapping(value = "/hello", method = RequestMethod.GET)
	public void hello() {
		logger.info("hello");
	}

	-------- TestService

	public void restTemplateCall() {
		logger.info("restTemplateCall");
		restTemplate.getForObject("http://localhost:8080/hello", Void.class);
	}
  • The result is two spans under the same Tracer. The figure is omitted
  • Similarly, microservice invocation based on OpenFeign must also be supported. The example is omitted

Messaging

Finally, we demonstrate the scenario of using message middleware, such as RabbitMq. We can manually put traceId and other information in Message.header for transmission, which is similar to the interceptor mechanism under the Web

RabbitMq example

	@Autowired
	SendService sendService;

	@RequestMapping(value = "send", method = RequestMethod.GET)
	public void send() {
		sendService.send();
	}

	-------- SendService
	
	private Logger logger = LoggerFactory.getLogger(this.getClass());

	@Autowired
	Tracer tracer;

	public void send() {

		MessageProperties properties = MessagePropertiesBuilder.newInstance()
				.setHeader("traceId", Optional.ofNullable(tracer)
						.map(t -> t.currentSpan())
						.map(span -> span.context())
						.map(context -> context.traceId())
						.orElse(""))
				.build();

		Message message = MessageBuilder
				.withBody("trace".getBytes())
				.andProperties(properties)
				.build();

		logger.info("send");

		rabbitTemplate.send(
				"test-direct-exchange", "test-trace-routekey", message
		);
	}

	------- RecieveService

	@RabbitListener(bindings = @QueueBinding(
			value = @Queue
			, exchange = @Exchange(value = "test-direct-exchange")
			, key = "test-trace-routekey"
	))
	public void trace(String message, @Header("traceId") String traceId) {
		System.out.println(message);
		System.out.println(traceId);
	}
  • The endpoint triggers sending messages and creates Tracer information
  • Include traceId information in the message header when sending a message
  • When receiving a message, you can get the traceId through @ Header for further processing
  • Results slightly

summary

There are other scenarios, such as OpenFeign, parent-child threads, Reactor (WebFlux), and so on

Tags: Java Spring Spring Cloud

Posted on Tue, 14 Sep 2021 01:32:56 -0400 by Cerebral Cow