Tracing in Spring Boot con OpenTracing / OpenTelemetry

In sistemi complessi e distribuiti, un tracciamento puntuale di cosa stanno facendo le nostre applicazioni e come avvengono le chiamate all’interno dell’architettura software può essere un aspetto fondamentale in alcuni casi di troubleshooting.

Ad esempio sapere esattamente all’interno di un’orchestrazione di microservizi, quale sia quello che sta impiegando più tempo del dovuto potrebbe non essere banale. In generale possiamo dire che un trace è la rappresentazione della sequenza di operazioni che stanno avvenendo e quindi utile anche per capire cosa viene fatto all’interno di una singola chiamata.

Quindi se il Trace è la rappresentazione di una singola chiamata, vedremo che questo è composto da una serie di Span che sono le operazioni puntuali presenti all’interno. All’interno della singola operazione possiamo poi avere altri dati che arricchiscono le informazioni utili (tag/log) per descrivere in maniera più dettagliata cosa sta succedendo cosa sta succedendo

Come in tutte le tecnologie esistono molteplici implementazioni di questo concetto. Uno dei tentativi che è stato fatto per la definizione di un API generica è OpenTracing, al quale possiamo fare riferimento nei nostri progetti senza dover necessariamente essere collegati ad una specifica implementazione. 

OpenTracing è stato utilizzato insieme a OpenCensus per dare vita a OpenTelemetry, progetto CNCF che con molta probabilità sarà il punto di riferimento nei prossimi anni per il tracciamento delle informazioni. Questi progetti sono alla fine simili a livello di concetti relativi al traccimento e in questo articolo vedremo OpenTracing e OpenTelemetry.

Jaeger

Esistono diverse implementazioni per gestire il tracing, quella che utilizzeremo in questo esempio è Jaeger, progetto CNCF che è stato inizialmente sviluppato da Uber. Una delle possibili architetture che possiamo utilizzare con Jaeger è quella riportata nella seguente immagine

Abbiamo quindi un client all’interno della nostra applicazione che attraverso un agent invia le informazioni (trace/span) al collector che si occupa di memorizzarle su un database. Infine è presente un’interfaccia grafica che può essere utilizzata per ricercare e visualizzare tutti i dati che vengono memorizzati. Per avviare velocemente in locale jaeger utilizzeremo all’interno del nostro articolo l’immagine jaegertracing/all-in-one che appunto include tutte le componenti 

Architettura d’esempio

In questo articolo vedremo una semplice interazione tra 3 componenti, 2 applicazioni e un database

L’applicazione A espone un servizio HTTP che richiama un servizio HTTP esposto dall’applicazione B. Questo servizio a sua volta richiama il database per fare una query

OpenTracing

Le applicazioni sono state realizzate utilizzando Spring Boot, per il quale è disponibile uno starter che abilita OpenTracing e nel caso specifico include l’implementazione per esportare le informazioni su Jaeger. Aggiungiamo quindi la seguente dipendenza al nostro pom.xml


       io.opentracing.contrib
       opentracing-spring-jaeger-cloud-starter
       3.2.0

Grazie a questa dipendenza verranno instrumentate in maniera automatica tutte le chiamate alle diverse componenti architetturali che possono essere presenti nel nostro sistema (app, db, cache etc. etc.). In aggiunta a questo possiamo definire una serie di settaggi, che inseriremo nelle nostre properties, dove andiamo a dire il nome della nostra applicazione e l’endpoint del servizio Jaeger

opentracing:
  jaeger:
    service-name: OpenTracingAppA
    enabled: TRUE
    udp-sender:
      host: jaeger

A questo punto dobbiamo il semplice codice che effettua la chiamata HTTP e che poi effettua una query sul database (H2 in memory), che potete trovare tranquillamente nei sorgenti dei progetti. L’unica cosa che andremo ad inserire a livello di codice nel progetto OpenTracingA sarà la seguente parte, dove ci agganciamo in maniera programmatica al Trace su cui stiamo scrivendo e aggiungiamo un nostro Span custom

Tracer tracer = GlobalTracer.get();
Tracer.SpanBuilder spanBuilder = tracer.buildSpan("CustomSpan")
        .withTag(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_SERVER);

Span span = spanBuilder.start();
Tags.COMPONENT.set(span, "AppAController");
span.setTag("testtag", "test");
span.finish();

Questo soltanto per far vedere che oltre a quello che viene definito nello starter che gestisce automaticamente la memorizzazione dei trace, potremmo avere la necessità di tracciare qualcosa di specifico o aggiuntivo.

OpenTelemetry

Per quanto riguarda l’esempio di OpenTelemetry avremo due progetti che fanno praticamente la stessa cosa, ma non ci sono dipendenze o properties riguardanti il tracing. Quello che faremo sarà andare a settare un agent nell’avvio dell’applicazione, come potete vedere nel Dockerfile seguente

FROM openjdk:11-jre
RUN mkdir -p /app/bin
COPY ./target/opentelemetry-app-b.jar /app/bin
COPY opentelemetry-javaagent-all.jar /app/bin
CMD java -Dotel.exporter=jaeger \
         -Dotel.exporter.jaeger.endpoint=jaeger:14250 \
         -Dotel.exporter.jaeger.service.name=OpenTelemetryAppB \
         -Dapplication.home=/app/bin/ \
         -Dapplication.name=OpenTelemetryAppB \
         -javaagent:/app/bin/opentelemetry-javaagent-all.jar \
         -jar \
         /app/bin/opentelemetry-app-b.jar

In questo modo abbiamo dato il puntamento verso Jaeger e l’informazione sul nostro servizio direttamente come parametri, senza includere niente nell’applicazione. 

Let’s trace

Utilizzando docker-compose andremo a raggruppare tutte le applicazioni di cui abbiamo bisogno

version: "3.6"
services:
  jaeger:
    image: jaegertracing/all-in-one
    ports:
      - 5775:5775/udp
      - 6831:6831/udp
      - 6832:6832/udp
      - 5778:5778
      - 16686:16686
      - 14268:14268
      - 14250:14250
      - 9411:9411

  opentracing-app-b:
     build: opentracing-app-b
     ports:
      - 8081:8081

  opentracing-app-a:
     build: opentracing-app-a
     ports:
      - 8080:8080

  opentelemetry-app-b:
     build: opentelemetry-app-b
     ports:
      - 9082:9082

  opentelemetry-app-a:
     build: opentelemetry-app-a
     ports:
      - 9081:9081

Poi per avviare tutto l’esempio basta lanciare lo script build.sh che in sequenza farà la build dei progetti d’esempio e lì farà partire con docker-compose. Una volta lanciati possiamo effettuare due diverse chiamate per vedere le due diverse modalità di tracing

http://localhost:8080/test-tracing (OpenTracing)

http://localhost:9081/test-tracing (OpenTelemetry)

Andiamo ora a visualizzare cosa è stato salvato su Jaeger a valle delle nostre chiamate, vedendo la sua interfaccia pubblicata all’indirizzo http://localhost:16686/search

E’ possibile vedere che tra i servizi troveremo le applicazioni che hanno inserito delle informazioni su Jaeger ed effettuando la ricerca possiamo vedere quali tracce sono collegate al servizio, con un veloce riassunto grafico che ci fa capire anche i tempi di queste operazioni. Cliccando sulla traccia registrata da OpenTracing troviamo le seguenti informazioni

di seguito invece la traccia registrata da OpenTelemetry

Conclusioni

Le informazioni che possiamo trovare utilizzando questi strumenti possono essere estremamente utili. In maniera del tutto gratuita riusciamo ad avere informazioni sulle tempistiche di ogni singola esecuzione e anche sull’ordine di chiamata. Sul tracing di OpenTelemetry vediamo in maniera abbastanza esaustiva tutto lo stack di chiamate che vengono fatte tra le diverse app/classi, inclusa la query che viene fatta da JPA sul database. Personalmente penso sia preferibile la modalità con l’agent finchè possibile, perchè in questo modo non dobbiamo “contaminare” la nostra applicazione in nessun modo.

Sul sito di OpenTelemetry è possibile vedere che sono stati implementati degli Exporter per progetti opensource famosi (Jaeger, Zipkin, Prometheus), i principali cloud provider (AWS, Azure, Google) e anche per servizi famosi di monitoraggio (Datadog, New relic).

Federico Paparoni

Looking for a right "about me"...