j’ai achetĂ© un PC...
Grafana Stack 📈 1. ObservabilitĂ© avec Spring Boot 3

Grafana Stack 📈 1. ObservabilitĂ© avec Spring Boot 3

⏱ 9 mn

À mes heures perdues, je travaille sur une application de veille techno qui me permet de faire la mienne (veille) comme j’ai envie. RĂ©cemment, j’ai entendu parler d’Opentelemetry un collecteur de tĂ©lĂ©mĂ©trie. Et j’ai eu envie de le tester pour voir si je pouvais rendre mon application observable.

Veille techno en temps libre
Il existe une multitude de stack de tĂ©lĂ©mĂ©trie, mais Grafana est open source et permet d’avoir assez facilement toutes les mĂ©triques sur la mĂȘme application de rendu. De plus, je voulais essayer Loki en comparaisons de ELK que j’utilise dĂ©jĂ  au travail.

VoilĂ  donc une sĂ©rie d’articles dĂ©taillants comment mettre en place l’observabilitĂ© sur une application Spring Boot 3.

Les autres articles de la série :

  1. Observabilité avec Spring Boot 3
  2. Collecte des métriques avec OpenTelemetry
  3. Collecte des logs avec OpenTelemetry

La Stack Grafana

Avant de commencer, parlons un peu de la stack grafana. Elle est composĂ©e de plusieurs Ă©lĂ©ments. Dans mon boulot prĂ©cĂ©dent et dans mon poste actuel, j’ai beaucoup travaillĂ© avec la stack ELK. Elle est trĂšs efficace, mais j’ai toujours trouvĂ© qu’elle Ă©tait compliquĂ©e Ă  mettre en place et Ă  configurer. C’est l’occasion de tester la stack Grafana plus simple Ă  mettre en Ɠuvre.

Prometheus

Prometheus à volé le feu aux dieux
Prometheus est le moteur de stockage de mĂ©triques. Il s’agit d’un moteur de mĂ©triques dimensionnel. Chaque mĂ©trique est reprĂ©sentĂ©e par un nom et par des attributs, un ensemble de clĂ©/valeur qui spĂ©cialise la donnĂ©e. Cela permet de faire des requĂȘtes puissantes, mais il faut faire attention Ă  ne pas avoir d’attributs dont l’ensemble de valeurs possible est trop important sans quoi les performances et l’espace de stockage vont exploser.

Loki

Loki est le moteur de stockage de logs. Mais, contrairement Ă  Elastic qui va indexer tout le contenu des logs, Loki ne va indexer que certains attributs. Loki stocke les logs comme prometheus les mĂ©triques. Chaque log possĂšde un ensemble d’attributs clĂ©/valeur qui sont indexĂ©s, le reste du message ne l’est pas. Comme pour les mĂ©triques on ne doit pas utiliser d’attribut avec un ensemble de valeurs trop grand sous peine de problĂšmes de performance et d’explosion du stockage. L’intĂ©rĂȘt de cette approche est que l’empreinte sur le disque est bien plus faible que pour un Elastic. L’inconvĂ©nient est qu’il n’est pas possible de faire de recherche sur les champs non indexĂ©s et donc sur le contenu du message de log.

Tempo

Tempo quant Ă  lui, va stocker les traces. C’est-Ă -dire le moyen de rapprocher les logs et les mĂ©triques dans un environnement micro-service. Cela fera l’objet d’un autre article.

Grafana

Enfin Grafana propose une interface unifiée pour visualiser toute cette télémétrie.

Spring Boot et l’observabilitĂ©

Spring observability

L’observabilitĂ© regroupe les 3 Ă©lĂ©ments suivants :

  • Les mĂ©triques
  • Les logs
  • Les traces

Sur les derniĂšres versions du framework, l’équipe de Spring a ajoutĂ© la fonctionnalitĂ© d’observabilitĂ© qui est particuliĂšrement bien intĂ©grĂ© au modĂšle Spring Webflux et Ă  la programmation rĂ©active grĂące Ă  Micrometer et Reactor.

Avec trĂšs peu de code additionnel il est maintenant possible d’obtenir des mĂ©triques dĂ©taillĂ©es pour chaque exĂ©cution de stream que l’on souhaite observer.

Déploiement des métriques

Ajout des dépendences

Tout d’abord dans le pom.xml :

<dependency>
    <groupId>io.projectreactor</groupId>
    <artifactId>reactor-core-micrometer</artifactId>
</dependency>

<dependency>
    <groupId>io.micrometer</groupId>
    <artifactId>micrometer-registry-prometheus</artifactId>
</dependency>

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-actuator</artifactId>
</dependency>
  • reactor-core-micrometer est le plugin d’observabilitĂ© de micrometer qui lui permet de s’intĂ©grer Ă  reactor.
  • micrometer-registry-prometheus reprĂ©sente le format de restitution des mĂ©triques. En effet, il existe plusieurs approches quant Ă  la collecte de mĂ©triques. L’approche choisie dĂ©termine le format de restitution. Dans notre cas, on va utiliser un Stack Grafana pour stocker et visualiser nos mĂ©triques, c’est donc le format prometheus (le moteur de stockage de mĂ©triques de grafana) qui correspond Ă  notre choix.
  • spring-boot-starter-actuator l’actuator va nous permettre de mettre Ă  disposition un API pour collecter les mĂ©triques

Configuration Spring Boot

Maintenant, il reste à ajouter la configuration de l’actuator dans le fichier application.yaml :

spring:
  application.name: MyApplication


management:
  endpoints.web.exposure.include: prometheus,health
  metrics:
    distribution.percentiles-histogram:
      http.server.requests: true

Pour ce qui est du nom de l’application, nous en aurons besoin plus tard. Pour le reste, la ligne importante est endpoints.web.exposure.include: prometheus qui va activer l’api de collecte pour prometheus. Le reste des paramĂštres permet d’avoir un peu plus de dĂ©tails dans les mĂ©triques collectĂ©es.

À partir de lĂ , l’application est dĂ©jĂ  capable de fournir une grosse quantitĂ© de mĂ©triques sur le fonctionnement de Spring et de la JVM. DĂ©marrer l’application et, avec un postman par exemple, faire une requĂȘte GET /actuator/prometheus qui est la route par dĂ©faut pour Prometheus.

# HELP jvm_threads_peak_threads The peak live thread count since the Java virtual machine started or peak was reset
# TYPE jvm_threads_peak_threads gauge
jvm_threads_peak_threads{context="MyApplication",} 45.0
# HELP jvm_gc_overhead_percent An approximation of the percent of CPU time used by GC activities over the last lookback period or since monitoring began, whichever is shorter, in the range [0..1]
# TYPE jvm_gc_overhead_percent gauge
jvm_gc_overhead_percent{context="MyApplication",} 0.00497286035688716
# HELP system_cpu_usage The "recent cpu usage" of the system the application is running in
# TYPE system_cpu_usage gauge
system_cpu_usage{context="MyApplication",} 0.0
# HELP process_files_max_files The maximum file descriptor count
# TYPE process_files_max_files gauge
process_files_max_files{context="MyApplication",} 1048576.0
# HELP bw_news_count Total number of News
# TYPE bw_news_count gauge
bw_news_count{context="MyApplication",} 0.0
# HELP jvm_gc_live_data_size_bytes Size of long-lived heap memory pool after reclamation
# TYPE jvm_gc_live_data_size_bytes gauge
jvm_gc_live_data_size_bytes{context="MyApplication",} 1.33460992E8
# HELP hikaricp_connections_max Max connections
# TYPE hikaricp_connections_max gauge
hikaricp_connections_max{context="MyApplication",pool="HikariPool-1",} 10.0
# HELP spring_security_authorizations_seconds  
# TYPE spring_security_authorizations_seconds summary
spring_security_authorizations_seconds_count{context="MyApplication",error="none",spring_security_authentication_type="UsernamePasswordAuthenticationToken",spring_security_authorization_decision="true",spring_security_object="exchange",} 1.0
spring_security_authorizations_seconds_sum{context="MyApplication",error="none",spring_security_authentication_type="UsernamePasswordAuthenticationToken",spring_security_authorization_decision="true",spring_security_object="exchange",} 0.005212113

Ce n’est qu’un exemple des mĂ©triques fournis de base par Spring, mais il y en a sur beaucoup d’aspects : La mĂ©moire, la consommation CPU, les routes appelĂ©es, le temps de dĂ©marrage, …

Ajout de la premiÚre métrique

Dans le cadre de l’application de veille techno, j’ai un process de scraping des feed de news qui se dĂ©clenche toutes les heures et ça m’intĂ©resserait bien de l’observer.

Le code de ce processus est un flux Reactor qui exécute toutes les étapes, lancé à intervales réguliers par un Scheduler :

@Override
public void run() {
    log.info("Start scraping ...");
    scraperService.scrap(properties.conservation())
            .subscribe();
}

J’ai simplifiĂ© le code rĂ©el, mais l’idĂ©e est lĂ .

// Injection de l’ObservationRegistry via le constructeur
private final ObservationRegistry observationRegistry;

@Override
public void run() {
    log.info("Start scraping ...");
    scraperService.scrap(properties.conservation())
            .name("bw_scraping_process")
            .tap(Micrometer.observation(observationRegistry))
            .subscribe();
}

Si on relance l’application maintenant et que l’on attend que le process de scraping se termine. Puis, que l’on interroge Ă  nouveau la route GET /actuator/prometheus. On obtient les donnĂ©es supplĂ©mentaires suivantes.

# HELP bw_scraping_process_seconds  
# TYPE bw_scraping_process_seconds summary
bw_scraping_process_seconds_count{context="MyApplication",error="none",reactor_status="completed",reactor_type="Mono",} 1.0
bw_scraping_process_seconds_sum{context="MyApplication",error="none",reactor_status="completed",reactor_type="Mono",} 17.026397336
# HELP bw_scraping_process_seconds_max  
# TYPE bw_scraping_process_seconds_max gauge
bw_scraping_process_seconds_max{context="MyApplication",error="none",reactor_status="completed",reactor_type="Mono",} 17.026397336
# HELP bw_scraping_process_active_seconds_max  
# TYPE bw_scraping_process_active_seconds_max gauge
bw_scraping_process_active_seconds_max{context="MyApplication",reactor_type="Mono",} 0.0
# HELP bw_scraping_process_active_seconds  
# TYPE bw_scraping_process_active_seconds summary
bw_scraping_process_active_seconds_active_count{context="MyApplication",reactor_type="Mono",} 0.0
bw_scraping_process_active_seconds_duration_sum{context="MyApplication",reactor_type="Mono",} 0.0

L’observabilitĂ© de reactor produit en tout 2 groupes de 3 mĂ©triques :

  • Les mĂ©triques d’exĂ©cution
    • le nombre total d’appels
    • la durĂ©e maximale
    • la somme des durĂ©es
  • Les mĂ©triques d’exĂ©cution longue (active) qui donne les mĂȘmes compteurs pour des opĂ©rations de plus longues durĂ©es qui ne seraient pas terminĂ©es.

Utilisation d’une Gauge

Ces mĂ©triques sont pratiques, mais pas simple Ă  interprĂ©ter. Finalement, si vous souhaitez voir l’évolution de la durĂ©e du scraping au fil du temps, cela n’est pas possible. Au mieux, vous avez la durĂ©e moyenne. C’est pour cela qu’il peut ĂȘtre intĂ©ressant de dĂ©clarer une Gauge qui va permettre cette observation.

private final AtomicLong lastScrapingDuration = new AtomicLong(0);

public ScraperTaskScheduler(MeterRegistry registry) {
    TimeGauge.builder("bw_scraping_process", lastScrapingDuration::get, TimeUnit.MILLISECONDS)
            .description("Last scraping duration")
            .register(registry);
}

@Override
public void run() {
    log.info("Start scraping ...");
    long startTime = System.currentTimeMillis();
    scraperService.scrap(properties.conservation())
            .doFinally(s -> lastScrapingDuration.set(System.currentTimeMillis() - startTime))
            .subscribe();
}

Les TimeGauge permettent d’ajouter au compteur une unitĂ© de temps.

Maintenant si on relance l’application pour voir les compteurs, voilà ce que l’on a.

# HELP bw_scraping_process_seconds Last scraping duration
# TYPE bw_scraping_process_seconds gauge
bw_scraping_process_seconds{context="MyApplication",} 14.201

Ce n’est pas flagrant comme changement mais, dans le cas d’une gauge, chaque nouvelle valeur vient remplacer la prĂ©cĂ©dente. Contrairement Ă  un timer ou un compteur qui additionne chaque nouvelle valeur avec la prĂ©cĂ©dente.

Ajout du contexte

Dans toutes les mĂ©triques dĂ©critent dans cet article, on peut voir l’attribut context=MyApplication. Ce contexte est important, car dans Prometheus, il nous permettra de selectionner les mĂ©triques de la bonne application Spring (si vous en avez plusieurs). Pour faire ça, il faut ajouter un MeterRegistryCustomizer.

@Configuration
public class SpringConfiguration {
    @Bean
    public MeterRegistryCustomizer<MeterRegistry> metricsCommonTags(@Value("${spring.application.name}") String application) {
        return registry -> registry.config()
                .commonTags("context", application.toLowerCase());
    }
}

Il est possible d’en ajouter d’autre, comme l’identifiant de l’instance si vous avez un cluster.

SĂ©curisation

Dernier point important, la sĂ©curisation du point d’accĂšs aux mĂ©triques. Pensez Ă  sĂ©curiser ce point d’accĂšs, mĂȘme si y accĂ©der ne suffira pas Ă  pirater l’application, les mĂ©triques laissent passer bon nombre d’informations exploitables qui permettrait Ă  une personne mal intentionnĂ©e de dĂ©nicher d’éventuelles failles de sĂ©curitĂ©s.

Amélioration des logs

Logs de spring boot en JSON
Les logs par défaut de Spring sont vraiment appréciables et bien formatés. Mais des logs au format texte restent un enfer à parser. Tous ceux qui ont travaillé un peu avec Logstash ont leurs collections de grok bien au chaud pour ce genre de chose.

Le plus simple est de faire en sorte que Spring sorte les logs en JSON, dĂ©jĂ  parsĂ©, elles seront directement lisibles par le collecteur. L’idĂ©al serait que l’on puisse rĂ©gler ça grĂące Ă  une variable d’environnement, ce qui permettrait de garder les logs “humain” pendant le dĂ©veloppement et d’utiliser le json pour la production.

Logback possĂšde un plugin qui permet d’obtenir ce rĂ©sultat.

Ajouter les dépendances

<dependency>
    <groupId>ch.qos.logback.contrib</groupId>
    <artifactId>logback-json-classic</artifactId>
    <version>0.1.5</version>
</dependency>
<dependency>
    <groupId>ch.qos.logback.contrib</groupId>
    <artifactId>logback-jackson</artifactId>
    <version>0.1.5</version>
</dependency>

Configuration logback

Ensuite on configure logback comme suit dans un fichier logback-spring.xml:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <springProperty scope="context" name="appName" source="spring.application.name"/>
    <springProperty scope="context" name="rootLevel" source="logging.level.root"/>

    <springProfile name="json-logging">
        <contextName>${appName}</contextName>
        <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
            <layout class="ch.qos.logback.contrib.json.classic.JsonLayout">
                <jsonFormatter class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter"/>
                <timestampFormat>${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd'T'HH:mm:ss.SSS'Z'}</timestampFormat>
                <appendLineSeparator>true</appendLineSeparator>
                <prettyPrint>false</prettyPrint>
            </layout>
        </appender>
        <statusListener class="ch.qos.logback.core.status.NopStatusListener" />
    </springProfile>

    <springProfile name="!json-logging">
        <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>
    </springProfile>

    <root level="${rootLevel}">
        <appender-ref ref="CONSOLE"/>
    </root>
</configuration>

L’intĂ©rĂȘt de cette configuration, c’est qu’elle est attachĂ©e au profil. Il est donc facile de passer de cette configuration Ă  la configuration par dĂ©faut des logs via la variable d’environnement SPRING_PROFILES_ACTIVE=json-logging.

À noter l’utilisation de spring.application.name que l’on a mis Ă  jour dans les propriĂ©tĂ©s de l’application et qui va se retrouver dans le contexte. Ce qui permettra de distinguer les logs de notre application d’autres logs dans loki et qui mettra ainsi le mĂȘme contexte sur nos mĂ©triques et sur les logs.

Relancer l’application

Si on relance l’application avec la configuration que l’on vient de mettre en place, voilà ce que cela va donner :

{"timestamp":"2023-05-30T23:07:12.880Z","level":"INFO","thread":"main","logger":"fr.ght1pc9kc.myapp.MyApplication","message":"Starting MyApplication using Java 17.0.6 with PID 31428 ( started by marthym in )","context":"MyApplication"}
{"timestamp":"2023-05-30T23:07:12.893Z","level":"DEBUG","thread":"main","logger":"fr.ght1pc9kc.myapp.MyApplication","message":"Running with Spring Boot v3.1.0, Spring v6.0.9","context":"MyApplication"}
{"timestamp":"2023-05-30T23:07:12.894Z","level":"INFO","thread":"main","logger":"fr.ght1pc9kc.myapp.MyApplication","message":"The following 1 profile is active: \"json-logging\"","context":"MyApplication"}
{"timestamp":"2023-05-30T23:07:13.973Z","level":"INFO","thread":"main","logger":"org.flywaydb.core.internal.license.VersionPrinter","message":"Flyway Community Edition 9.16.3 by Redgate","context":"MyApplication"}
{"timestamp":"2023-05-30T23:07:13.973Z","level":"INFO","thread":"main","logger":"org.flywaydb.core.internal.license.VersionPrinter","message":"See release notes here: https://rd.gt/416ObMi","context":"MyApplication"}
{"timestamp":"2023-05-30T23:07:13.973Z","level":"INFO","thread":"main","logger":"org.flywaydb.core.internal.license.VersionPrinter","message":"","context":"MyApplication"}
{"timestamp":"2023-05-30T23:07:13.980Z","level":"INFO","thread":"main","logger":"com.zaxxer.hikari.HikariDataSource","message":"HikariPool-1 - Starting...","context":"MyApplication"}
{"timestamp":"2023-05-30T23:07:14.067Z","level":"INFO","thread":"main","logger":"com.zaxxer.hikari.pool.HikariPool","message":"HikariPool-1 - Added connection org.sqlite.jdbc4.JDBC4Connection@6f8667bb","context":"MyApplication"}
{"timestamp":"2023-05-30T23:07:14.068Z","level":"INFO","thread":"main","logger":"com.zaxxer.hikari.HikariDataSource","message":"HikariPool-1 - Start completed.","context":"MyApplication"}

Beaucoup plus difficile Ă  lire pour un humain, mais bien plus simple Ă  parser.

Conclusion

VoilĂ  les quelques amĂ©liorations Ă  mettre en place dans une application Spring pour simplifier la collecte des mĂ©triques. Dans le prochain article, nous verrons comment mettre en place un collecteur OpenTelemetry et rĂ©cupĂ©rer les mĂ©triques que l’on vient de configurer.


Grafana Stack 📈 1. ObservabilitĂ© avec Spring Boot 3 est paru le