Spring Cloud Sleuth in a Monolith Application – 单片机应用中的Spring Cloud Sleuth

最后修改: 2017年 1月 22日

中文/混合/英文(键盘快捷键:t)

1. Overview

1.概述

In this article, we’re introducing Spring Cloud Sleuth – a powerful tool for enhancing logs in any application, but especially in a system built up of multiple services.

在这篇文章中,我们将介绍Spring Cloud Sleuth–这是一个强大的工具,用于增强任何应用程序中的日志,但特别是在由多个服务构建的系统中。

And for this writeup we’re going to focus on using Sleuth in a monolith application, not across microservices.

在这篇报道中,我们将重点讨论在单体应用中使用Sleuth,而不是跨微服务

We’ve all had the unfortunate experience of trying to diagnose a problem with a scheduled task, a multi-threaded operation, or a complex web request. Often, even when there is logging, it is hard to tell what actions need to be correlated together to create a single request.

我们都有过这样不幸的经历:试图诊断一个预定任务、一个多线程操作或一个复杂的网络请求的问题。通常情况下,即使有日志记录,也很难分辨出哪些操作需要关联在一起以创建一个单一的请求。

This can make diagnosing a complex action very difficult or even impossible. Often resulting in solutions like passing a unique id to each method in the request to identify the logs.

这可能会使诊断一个复杂的行动非常困难,甚至不可能。通常导致的解决方案是在请求中为每个方法传递一个唯一的ID,以识别日志。

In comes Sleuth. This library makes it possible to identify logs pertaining to a specific job, thread, or request. Sleuth integrates effortlessly with logging frameworks like Logback and SLF4J to add unique identifiers that help track and diagnose issues using logs.

这就是 Sleuth。这个库使得识别与特定工作、线程或请求有关的日志成为可能。Sleuth毫不费力地与LogbackSLF4J等日志框架集成,以添加独特的标识符,帮助跟踪和诊断使用日志的问题。

Let’s take a look at how it works.

让我们来看看它是如何工作的。

2. Setup

2.设置

We’ll start by creating a Spring Boot web project in our favorite IDE and adding this dependency to our pom.xml file:

我们将首先在我们最喜欢的IDE中创建一个Spring Boot web项目,并将这个依赖性添加到我们的pom.xml文件中。

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

Our application runs with Spring Boot and the parent pom provides versions for each entry. The latest version of this dependency can be found here: spring-cloud-starter-sleuth.

我们的应用程序使用Spring Boot运行,父pom为每个条目提供版本。这个依赖关系的最新版本可以在这里找到。spring-cloud-starter-sleuth

Additionally, let’s add an application name to instruct Sleuth to identify this application’s logs.

此外,让我们添加一个应用程序名称,以指示Sleuth识别这个应用程序的日志。

In our application.properties file add this line:

在我们的application.properties文件中添加这一行。

spring.application.name=Baeldung Sleuth Tutorial

3. Sleuth Configurations

3.侦探的配置

Sleuth is capable of enhancing logs in many situations. Starting with version 2.0.0, Spring Cloud Sleuth uses Brave as the tracing library that adds unique ids to each web request that enters our application. Furthermore, the Spring team has added support for sharing these ids across thread boundaries.

Sleuth能够在许多情况下增强日志。从 2.0.0 版本开始,Spring Cloud Sleuth 使用 Brave 作为跟踪库,为进入我们应用程序的每个 Web 请求添加唯一的 id。此外,Spring团队还增加了对跨线程边界共享这些ID的支持。

Traces can be thought of like a single request or job that is triggered in an application. All the various steps in that request, even across application and thread boundaries, will have the same traceId.

追踪可以被认为是一个应用程序中被触发的单一请求或工作。该请求中的所有不同步骤,甚至跨越应用程序和线程的界限,都有相同的traceId。

Spans, on the other hand, can be thought of as sections of a job or request. A single trace can be composed of multiple spans each correlating to a specific step or section of the request. Using trace and span ids we can pinpoint exactly when and where our application is as it processes a request. Making reading our logs much easier.

另一方面,跨度可以被认为是一个工作或请求的部分。一个单一的跟踪可以由多个跨度组成,每个跨度与请求的一个特定步骤或部分相关。使用跟踪和跨度ID,我们可以准确地指出我们的应用程序在处理一个请求时的时间和地点。使得阅读我们的日志更加容易。

In our examples, we will explore these capabilities in a single application.

在我们的例子中,我们将在一个单一的应用程序中探索这些能力。

3.1. Simple Web Request

<简单的网络请求

First, let’s create a controller class to be an entry point to work with:

首先,让我们创建一个控制器类,作为工作的入口。

@RestController
public class SleuthController {

    @GetMapping("/")
    public String helloSleuth() {
        logger.info("Hello Sleuth");
        return "success";
    }
}

Let’s run our application and navigate to “http://localhost:8080”. Watch the logs for output that looks like:

让我们运行我们的应用程序并导航到 “http://localhost:8080″。观察日志中的输出,看起来像。

2017-01-10 22:36:38.254  INFO 
  [Baeldung Sleuth Tutorial,4e30f7340b3fb631,4e30f7340b3fb631,false] 12516 
  --- [nio-8080-exec-1] c.b.spring.session.SleuthController : Hello Sleuth

This looks like a normal log, except for the part in the beginning between the brackets. This is the core information that Spring Sleuth has added. This data follows the format of:

这看起来像一个正常的日志,除了开头括号之间的部分。这是Spring Sleuth添加的核心信息。这些数据的格式是:。

[application name, traceId, spanId, export]

[应用程序名称,traceId,spanId,export]

  • Application name – This is the name we set in the properties file and can be used to aggregate logs from multiple instances of the same application.
  • TraceId – This is an id that is assigned to a single request, job, or action. Something like each unique user initiated web request will have its own traceId.
  • SpanId – Tracks a unit of work. Think of a request that consists of multiple steps. Each step could have its own spanId and be tracked individually. By default, any application flow will start with same TraceId and SpanId.
  • Export – This property is a boolean that indicates whether or not this log was exported to an aggregator like Zipkin. Zipkin is beyond the scope of this article but plays an important role in analyzing logs created by Sleuth.

By now, you should have some idea of the power of this library. Let’s take a look at another example to further demonstrate how integral this library is to logging.

现在,你应该对这个库的力量有了一些了解。让我们看看另一个例子,以进一步证明这个库对日志记录是多么不可或缺。

3.2. Simple Web Request With Service Access

3.2.带有服务访问的简单网络请求

Let’s start by creating a service with a single method:

让我们从创建一个具有单一方法的服务开始。

@Service
public class SleuthService {

    public void doSomeWorkSameSpan() {
        Thread.sleep(1000L);
        logger.info("Doing some work");
    }
}

Now let’s inject our service into our controller and add a request mapping method that accesses it:

现在让我们把服务注入控制器,并添加一个访问它的请求映射方法。

@Autowired
private SleuthService sleuthService;
    
    @GetMapping("/same-span")
    public String helloSleuthSameSpan() throws InterruptedException {
        logger.info("Same Span");
        sleuthService.doSomeWorkSameSpan();
        return "success";
}

Finally, restart the application and navigate to “http://localhost:8080/same-span”. Watch for log output that looks like:

最后,重新启动应用程序并导航到 “http://localhost:8080/same-span”。观察日志输出,看起来像。

2017-01-10 22:51:47.664  INFO 
  [Baeldung Sleuth Tutorial,b77a5ea79036d5b9,b77a5ea79036d5b9,false] 12516 
  --- [nio-8080-exec-3] c.b.spring.session.SleuthController      : Same Span
2017-01-10 22:51:48.664  INFO 
  [Baeldung Sleuth Tutorial,b77a5ea79036d5b9,b77a5ea79036d5b9,false] 12516 
  --- [nio-8080-exec-3] c.baeldung.spring.session.SleuthService  : Doing some work

Take note that the trace and span ids are the same between the two logs even though the messages originate from two different classes. This makes it trivial to identify each log during a request by searching for the traceId of that request.

请注意,即使消息来自两个不同的类,两个日志之间的跟踪和跨度ID也是相同的。这使得在请求期间通过搜索该请求的traceId来识别每条日志变得非常简单。

This is the default behavior, one request gets a single traceId and spanId. But we can manually add spans as we see fit. Let’s take a look at an example that uses this feature.

这是默认行为,一个请求得到一个traceIdspanId。但是我们可以根据我们的需要手动添加跨度。让我们来看看一个使用这个功能的例子。

3.3. Manually Adding a Span

3.3.手动添加一个跨度

To start, let’s add a new controller:

首先,让我们添加一个新的控制器。

@GetMapping("/new-span")
public String helloSleuthNewSpan() {
    logger.info("New Span");
    sleuthService.doSomeWorkNewSpan();
    return "success";
}

And now let’s add the new method inside our service:

现在让我们在我们的服务中添加新的方法。

@Autowired
private Tracer tracer;
// ...
public void doSomeWorkNewSpan() throws InterruptedException {
    logger.info("I'm in the original span");

    Span newSpan = tracer.nextSpan().name("newSpan").start();
    try (SpanInScope ws = tracer.withSpanInScope(newSpan.start())) {
        Thread.sleep(1000L);
        logger.info("I'm in the new span doing some cool work that needs its own span");
    } finally {
        newSpan.finish();
    }

    logger.info("I'm in the original span");
}

Note that we also added a new object, Tracer. The tracer instance is created by Spring Sleuth during startup and is made available to our class through dependency injection.

请注意,我们还添加了一个新对象,TracerTracer实例由Spring Sleuth在启动时创建,并通过依赖注入提供给我们的类。

Traces must be manually started and stopped. To accomplish this, code that runs in a manually created span is placed inside a try-finally block to ensure the span is closed regardless of the operation’s success. Also, notice that new span has to be placed in scope.

追踪必须被手动启动和停止。为了达到这个目的,在手动创建的span中运行的代码被放在try-finally块内,以确保无论操作是否成功,span都被关闭。另外,注意到新的span必须被放置在范围内。

Restart the application and navigate to “http://localhost:8080/new-span”. Watch for the log output that looks like:

重新启动应用程序并导航到 “http://localhost:8080/new-span”。观察日志输出,看起来像。

2017-01-11 21:07:54.924  
  INFO [Baeldung Sleuth Tutorial,9cdebbffe8bbbade,9cdebbffe8bbbade,false] 12516 
  --- [nio-8080-exec-6] c.b.spring.session.SleuthController      : New Span
2017-01-11 21:07:54.924  
  INFO [Baeldung Sleuth Tutorial,9cdebbffe8bbbade,9cdebbffe8bbbade,false] 12516 
  --- [nio-8080-exec-6] c.baeldung.spring.session.SleuthService  : 
  I'm in the original span
2017-01-11 21:07:55.924  
  INFO [Baeldung Sleuth Tutorial,9cdebbffe8bbbade,1e706f252a0ee9c2,false] 12516 
  --- [nio-8080-exec-6] c.baeldung.spring.session.SleuthService  : 
  I'm in the new span doing some cool work that needs its own span
2017-01-11 21:07:55.924  
  INFO [Baeldung Sleuth Tutorial,9cdebbffe8bbbade,9cdebbffe8bbbade,false] 12516 
  --- [nio-8080-exec-6] c.baeldung.spring.session.SleuthService  : 
  I'm in the original span

We can see that the third log shares the traceId with the others, but it has a unique spanId. This can be used to locate different sections in a single request for more fine-grained tracing.

我们可以看到,第三条日志与其他日志共享traceId,但它有一个独特的spanId。这可以用来定位单个请求中的不同部分,以便进行更精细的追踪。

Now let’s take a look at Sleuth’s support for threads.

现在让我们看看Sleuth的对线程的支持。

3.4. Spanning Runnables

3.4.跨越式可操作性

To demonstrate the threading capabilities of Sleuth let’s first add a configuration class to set up a thread pool:

为了演示Sleuth的线程功能,我们首先添加一个配置类来设置一个线程池。

@Configuration
public class ThreadConfig {

    @Autowired
    private BeanFactory beanFactory;

    @Bean
    public Executor executor() {
        ThreadPoolTaskExecutor threadPoolTaskExecutor
         = new ThreadPoolTaskExecutor();
        threadPoolTaskExecutor.setCorePoolSize(1);
        threadPoolTaskExecutor.setMaxPoolSize(1);
        threadPoolTaskExecutor.initialize();

        return new LazyTraceExecutor(beanFactory, threadPoolTaskExecutor);
    }
}

It is important to note here the use of LazyTraceExecutor. This class comes from the Sleuth library and is a special kind of executor that will propagate our traceIds to new threads and create new spanIds in the process.

这里需要注意的是LazyTraceExecutor的使用。这个类来自Sleuth库,是一种特殊的执行器,它将把我们的traceIds传播到新的线程,并在这个过程中创建新的spanIds。

Now let’s wire this executor into our controller and use it in a new request mapping method:

现在让我们把这个执行器接入我们的控制器,并在一个新的请求映射方法中使用它。

@Autowired
private Executor executor;
    
    @GetMapping("/new-thread")
    public String helloSleuthNewThread() {
        logger.info("New Thread");
        Runnable runnable = () -> {
            try {
                Thread.sleep(1000L);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
            logger.info("I'm inside the new thread - with a new span");
        };
        executor.execute(runnable);

        logger.info("I'm done - with the original span");
        return "success";
}

With our runnable in place, let’s restart our application and navigate to “http://localhost:8080/new-thread”. Watch for log output that looks like:

有了我们的runnable,让我们重新启动我们的应用程序并导航到 “http://localhost:8080/new-thread”。观察一下日志输出,看起来像。

2017-01-11 21:18:15.949  
  INFO [Baeldung Sleuth Tutorial,96076a78343c364d,96076a78343c364d,false] 12516 
  --- [nio-8080-exec-9] c.b.spring.session.SleuthController      : New Thread
2017-01-11 21:18:15.950  
  INFO [Baeldung Sleuth Tutorial,96076a78343c364d,96076a78343c364d,false] 12516 
  --- [nio-8080-exec-9] c.b.spring.session.SleuthController      : 
  I'm done - with the original span
2017-01-11 21:18:16.953  
  INFO [Baeldung Sleuth Tutorial,96076a78343c364d,e3b6a68013ddfeea,false] 12516 
  --- [lTaskExecutor-1] c.b.spring.session.SleuthController      : 
  I'm inside the new thread - with a new span

Much like the previous example we can see that all the logs share the same traceId. But the log coming from the runnable has a unique span that will track the work done in that thread. Remember that this happens because of the LazyTraceExecutor, if we were to use a normal executor we would continue to see the same spanId used in the new thread.

和前面的例子一样,我们可以看到所有的日志都共享同一个traceId。但是来自runnable的日志有一个独特的跨度,它将跟踪该线程中的工作。请记住,这是因为LazyTraceExecutor而发生的,如果我们使用一个正常的执行器,我们将继续看到在新线程中使用相同的spanId

Now let’s look into Sleuth’s support for @Async methods.

现在我们来看看Sleuth的@Async方法的支持。

3.5. @Async Support

3.5.@Async支持

To add async support let’s first modify our ThreadConfig class to enable this feature:

为了添加异步支持,我们首先要修改我们的ThreadConfig类来启用这个功能。

@Configuration
@EnableAsync
public class ThreadConfig extends AsyncConfigurerSupport {
    
    //...
    @Override
    public Executor getAsyncExecutor() {
        ThreadPoolTaskExecutor threadPoolTaskExecutor = new ThreadPoolTaskExecutor();
        threadPoolTaskExecutor.setCorePoolSize(1);
        threadPoolTaskExecutor.setMaxPoolSize(1);
        threadPoolTaskExecutor.initialize();

        return new LazyTraceExecutor(beanFactory, threadPoolTaskExecutor);
    }
}

Note that we extend AsyncConfigurerSupport to specify our async executor and use LazyTraceExecutor to ensure traceIds and spanIds are propagated correctly. We have also added @EnableAsync to the top of our class.

请注意,我们扩展了AsyncConfigurerSupport以指定我们的异步执行器,并使用LazyTraceExecutor以确保traceIds和spanIds被正确传播。我们还在类的顶部添加了@EnableAsync

Let’s now add an async method to our service:

现在让我们为我们的服务添加一个异步方法。

@Async
public void asyncMethod() {
    logger.info("Start Async Method");
    Thread.sleep(1000L);
    logger.info("End Async Method");
}

Now let’s call into this method from our controller:

现在让我们从我们的控制器中调用这个方法。

@GetMapping("/async")
public String helloSleuthAsync() {
    logger.info("Before Async Method Call");
    sleuthService.asyncMethod();
    logger.info("After Async Method Call");
    
    return "success";
}

Finally, let’s restart our service and navigate to “http://localhost:8080/async”. Watch for the log output that looks like:

最后,让我们重新启动我们的服务并导航到 “http://localhost:8080/async”。注意看一下日志输出,看起来像。

2017-01-11 21:30:40.621  
  INFO [Baeldung Sleuth Tutorial,c187f81915377fff,c187f81915377fff,false] 10072 
  --- [nio-8080-exec-2] c.b.spring.session.SleuthController      : 
  Before Async Method Call
2017-01-11 21:30:40.622  
  INFO [Baeldung Sleuth Tutorial,c187f81915377fff,c187f81915377fff,false] 10072 
  --- [nio-8080-exec-2] c.b.spring.session.SleuthController      : 
  After Async Method Call
2017-01-11 21:30:40.622  
  INFO [Baeldung Sleuth Tutorial,c187f81915377fff,8a9f3f097dca6a9e,false] 10072 
  --- [lTaskExecutor-1] c.baeldung.spring.session.SleuthService  : 
  Start Async Method
2017-01-11 21:30:41.622  
  INFO [Baeldung Sleuth Tutorial,c187f81915377fff,8a9f3f097dca6a9e,false] 10072 
  --- [lTaskExecutor-1] c.baeldung.spring.session.SleuthService  : 
  End Async Method

We can see here that much like our runnable example, Sleuth propagates the traceId into the async method and adds a unique spanId.

我们可以看到,与我们的可运行例子一样,SleuthtraceId传播到async方法中,并添加一个唯一的spanId。

Let’s now work through an example using spring support for scheduled tasks.

现在让我们通过一个使用spring支持计划任务的例子。

3.6. @Scheduled Support

3.6.@Scheduled支持

Finally, let’s look at how Sleuth works with @Scheduled methods. To do this let’s update our ThreadConfig class to enable scheduling:

最后,让我们看看Sleuth如何与@Scheduled方法一起工作。要做到这一点,让我们更新我们的ThreadConfig类以启用调度。

@Configuration
@EnableAsync
@EnableScheduling
public class ThreadConfig extends AsyncConfigurerSupport
  implements SchedulingConfigurer {
 
    //...
    
    @Override
    public void configureTasks(ScheduledTaskRegistrar scheduledTaskRegistrar) {
        scheduledTaskRegistrar.setScheduler(schedulingExecutor());
    }

    @Bean(destroyMethod = "shutdown")
    public Executor schedulingExecutor() {
        return Executors.newScheduledThreadPool(1);
    }
}

Note that we have implemented the SchedulingConfigurer interface and overridden its configureTasks method. We have also added @EnableScheduling to the top of our class.

请注意,我们已经实现了SchedulingConfigurer接口并重载了其configureTasks方法。我们还添加了@EnableScheduling到我们的类的顶部。

Next, let’s add a service for our scheduled tasks:

接下来,让我们为我们的计划任务添加一个服务。

@Service
public class SchedulingService {

    private Logger logger = LoggerFactory.getLogger(this.getClass());
 
    @Autowired
    private SleuthService sleuthService;

    @Scheduled(fixedDelay = 30000)
    public void scheduledWork() throws InterruptedException {
        logger.info("Start some work from the scheduled task");
        sleuthService.asyncMethod();
        logger.info("End work from scheduled task");
    }
}

In this class, we have created a single scheduled task with a fixed delay of 30 seconds.

在这个类中,我们创建了一个固定延迟为30秒的单一计划任务。

Let’s now restart our application and wait for our task to be executed. Watch the console for output like this:

现在让我们重新启动我们的应用程序,等待我们的任务被执行。观察控制台的输出,像这样。

2017-01-11 21:30:58.866  
  INFO [Baeldung Sleuth Tutorial,3605f5deaea28df2,3605f5deaea28df2,false] 10072 
  --- [pool-1-thread-1] c.b.spring.session.SchedulingService     : 
  Start some work from the scheduled task
2017-01-11 21:30:58.866  
  INFO [Baeldung Sleuth Tutorial,3605f5deaea28df2,3605f5deaea28df2,false] 10072 
  --- [pool-1-thread-1] c.b.spring.session.SchedulingService     : 
  End work from scheduled task

We can see here that Sleuth has created new trace and span ids for our task. Each instance of a task will get it’s own trace and span by default.

我们可以看到,Sleuth已经为我们的任务创建了新的跟踪和跨度ID。默认情况下,每个任务的实例都会有自己的跟踪和跨度。

4. Conclusion

4.结论

In conclusion, we have seen how Spring Sleuth can be used in a variety of situations inside a single web application. We can use this technology to easily correlate logs from a single request, even when that request spans multiple threads.

总之,我们已经看到了Spring Sleuth如何在单个Web应用内的各种情况下使用。我们可以使用这项技术来轻松地关联来自单个请求的日志,即使该请求跨越了多个线程。

By now we can see how Spring Cloud Sleuth can help us keep our sanity when debugging a multi-threaded environment. By identifying each operation in a traceId and each step in a spanId we can really begin to break down our analysis of complex jobs in our logs.

现在我们可以看到Spring Cloud Sleuth如何帮助我们在调试多线程环境时保持理智。通过在traceId中识别每个操作,在spanId中识别每个步骤,我们可以真正开始分解分析日志中的复杂作业。

Even if we don’t go to the cloud, Spring Sleuth is likely a critical dependency in almost any project; it’s seamless to integrate and is a massive addition of value.

即使我们不去云端,Spring Sleuth也可能是几乎所有项目中的关键依赖因素;它可以无缝集成,是一个巨大的附加值

From here you may want to investigate other features of Sleuth. It can support tracing in distributed systems using RestTemplate, across messaging protocols used by RabbitMQ and Redis, and through a gateway like Zuul.

从这里开始,你可能想研究Sleuth的其他功能。它可以支持在使用RestTemplate的分布式系统中进行追踪,跨越RabbitMQRedis使用的消息传递协议,并通过Zuul等网关进行追踪。

As always you can find the source code over on Github.

像往常一样,你可以在Github上找到源代码over