Spring Cloud Sleuth dans une application Monolith

1. Vue d'ensemble

Dans cet article, nous présentons Spring Cloud Sleuth - un outil puissant pour améliorer les journaux dans n'importe quelle application, mais surtout dans un système composé de plusieurs services.

Et pour cet article, nous allons nous concentrer sur l'utilisation de Sleuth dans une application monolithique, et non sur des microservices .

Nous avons tous eu la malheureuse expérience d'essayer de diagnostiquer un problème avec une tâche planifiée, une opération multithread ou une requête Web complexe. Souvent, même en cas de journalisation, il est difficile de dire quelles actions doivent être mises en corrélation pour créer une seule demande.

Cela peut rendre le diagnostic d'une action complexe très difficile, voire impossible. Il en résulte souvent des solutions telles que la transmission d'un identifiant unique à chaque méthode dans la demande d'identification des journaux.

En vient Sleuth . Cette bibliothèque permet d'identifier les journaux relatifs à un travail, un thread ou une demande spécifique. Sleuth s'intègre sans effort aux cadres de journalisation tels que Logback et SLF4J pour ajouter des identifiants uniques qui aident à suivre et diagnostiquer les problèmes à l'aide de journaux.

Voyons comment cela fonctionne.

2. Configuration

Nous allons commencer par créer un projet Web Spring Boot dans notre IDE préféré et ajouter cette dépendance à notre fichier pom.xml :

 org.springframework.cloud spring-cloud-starter-sleuth 

Notre application fonctionne avec Spring Boot et le pom parent fournit des versions pour chaque entrée. La dernière version de cette dépendance peut être trouvée ici: spring-cloud-starter-sleuth. Pour voir l'intégralité du POM, consultez le projet sur Github.

De plus, ajoutons un nom d'application pour demander à Sleuth d'identifier les journaux de cette application.

Dans notre fichier application.properties , ajoutez cette ligne:

spring.application.name=Baeldung Sleuth Tutorial

3. Configurations de détective

Sleuth est capable d'améliorer les journaux dans de nombreuses situations. À partir de la version 2.0.0, Spring Cloud Sleuth utilise Brave comme bibliothèque de traçage qui ajoute des identifiants uniques à chaque requête Web qui entre dans notre application. En outre, l'équipe Spring a ajouté la prise en charge du partage de ces identifiants à travers les limites des threads.

Les traces peuvent être considérées comme une seule demande ou tâche déclenchée dans une application. Toutes les différentes étapes de cette demande, même au-delà des limites d'application et de thread, auront le même traceId.

Les portées, en revanche, peuvent être considérées comme des sections d'un travail ou d'une demande. Une seule trace peut être composée de plusieurs intervalles, chacun correspondant à une étape ou à une section spécifique de la demande. En utilisant les identifiants de trace et d'étendue, nous pouvons déterminer exactement quand et où se trouve notre application lorsqu'elle traite une demande. Rendre la lecture de nos journaux beaucoup plus facile.

Dans nos exemples, nous explorerons ces fonctionnalités dans une seule application.

3.1. Demande Web simple

Tout d'abord, créons une classe de contrôleur pour être un point d'entrée avec lequel travailler:

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

Lançons notre application et naviguons vers «// localhost: 8080». Regardez les journaux pour une sortie qui ressemble à:

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

Cela ressemble à un journal normal, sauf pour la partie au début entre les crochets. Ce sont les informations de base ajoutées par Spring Sleuth . Ces données suivent le format de:

[nom de l'application, traceId, spanId, export]

  • Nom de l'application - Il s'agit du nom que nous avons défini dans le fichier de propriétés et peut être utilisé pour agréger les journaux de plusieurs instances de la même application.
  • TraceId - Il s'agit d'un identifiant attribué à une seule demande, tâche ou action. Quelque chose comme chaque requête Web initiée par un utilisateur unique aura son propre traceId .
  • SpanId - Suit une unité de travail. Pensez à une demande qui se compose de plusieurs étapes. Chaque étape peut avoir son propre spanId et être suivie individuellement. Par défaut, tout flux d'application démarrera avec les mêmes TraceId et SpanId.
  • Exporter - Cette propriété est un booléen qui indique si ce journal a été exporté ou non vers un agrégateur tel que Zipkin . Zipkin sort du cadre de cet article mais joue un rôle important dans l'analyse des journaux créés par Sleuth .

À présent, vous devriez avoir une idée de la puissance de cette bibliothèque. Jetons un coup d'œil à un autre exemple pour démontrer davantage à quel point cette bibliothèque fait partie intégrante de la journalisation.

3.2. Demande Web simple avec accès au service

Commençons par créer un service avec une seule méthode:

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

Maintenant, injectons notre service dans notre contrôleur et ajoutons une méthode de mappage de requête qui y accède:

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

Enfin, redémarrez l'application et accédez à «// localhost: 8080 / same-span». Surveillez la sortie du journal qui ressemble à:

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

Notez que les identifiants de trace et d'étendue sont les mêmes entre les deux journaux, même si les messages proviennent de deux classes différentes. Cela rend simple l'identification de chaque journal lors d'une requête en recherchant le traceId de cette requête.

C'est le comportement par défaut, une requête obtient un seul traceId et spanId . Mais nous pouvons ajouter manuellement des travées comme bon nous semble. Jetons un coup d'œil à un exemple qui utilise cette fonctionnalité.

3.3. Ajout manuel d'une étendue

Pour commencer, ajoutons un nouveau contrôleur:

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

Et maintenant, ajoutons la nouvelle méthode à l'intérieur de notre 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"); }

Notez que nous avons également ajouté un nouvel objet, Tracer . L' instance de traceur est créée par Spring Sleuth au démarrage et est mise à la disposition de notre classe via l'injection de dépendances.

Les traces doivent être démarrées et arrêtées manuellement. Pour ce faire, le code qui s'exécute dans un intervalle créé manuellement est placé dans un bloc d' essai final pour garantir que l' étendue est fermée quel que soit le succès de l'opération. Notez également que la nouvelle étendue doit être placée dans la portée.

Redémarrez l'application et accédez à «// localhost: 8080 / new-span». Surveillez la sortie du journal qui ressemble à:

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

Nous pouvons voir que le troisième journal partage le traceId avec les autres, mais il a un spanId unique . Cela peut être utilisé pour localiser différentes sections en une seule demande pour un traçage plus fin.

Jetons maintenant un œil au support de Sleuth pour les threads.

3.4. Extension des runnables

Pour démontrer les capacités de thread de Sleuth , ajoutons d'abord une classe de configuration pour configurer un pool de threads:

@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); } }

Il est important de noter ici l'utilisation de LazyTraceExecutor . Cette classe provient de la bibliothèque Sleuth et est un type spécial d'exécuteur qui propage nos traceId à de nouveaux threads et crée de nouveaux spanId dans le processus.

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 “//localhost:8080/new-thread”. Watch for log output that looks like:

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.

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

3.5. @Async Support

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

@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.

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 “//localhost:8080/async”. Watch for the log output that looks like:

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.

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

3.6. @Scheduled Support

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

@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.

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.

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.

4. Conclusion

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.

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.

Même si nous n'allons pas dans le cloud, Spring Sleuth est probablement une dépendance critique dans presque tous les projets; il est transparent à intégrer et représente une valeur ajoutée considérable .

À partir de là, vous souhaiterez peut-être étudier d'autres fonctionnalités de Sleuth . Il peut prendre en charge le traçage dans les systèmes distribués à l'aide de RestTemplate , sur les protocoles de messagerie utilisés par RabbitMQ et Redis , et via une passerelle telle que Zuul.

Comme toujours, vous pouvez trouver le code source sur Github.