Tracing in verteilten Anwendungen

Michael Vitz

Wie ich mit Sicherheit schon einmal in einer Einleitung erwähnt habe, entfaltet Code, den wir geschrieben haben, erst seinen Wert, wenn dieser in Produktion läuft und genutzt werden kann. Dabei ist nicht nur die Zeit relevant, die von der Fertigstellung eines Features bis zum Deployment in Produktion vergeht, sondern auch, dass unser System stabil läuft und, im Rahmen der geforderten Qualitätsziele, zur Verfügung steht.

Noch vor Kurzem haben wir uns dabei auf wenige technische Metriken unseres Applikationsservers und klassische Monitoring-Tools wie Nagios verlassen. Neue Einflüsse, wie Microservice-Architekturen oder Cloud-Umgebungen, haben jedoch auch hier ihre Spuren hinterlassen. Unsere Systeme bestehen heute aus deutlich mehr und dynamischeren Teilen als früher. Und auch die DevOps-Bewegung hat dazu geführt, dass wir uns mehr Gedanken um den Betrieb unseres Systems machen.

Der moderne Ansatz für die Überwachung lautet Observability. Ziel hierbei ist es nicht, sich vorab Gedanken darum machen zu müssen, wie wir erkennen können, ob es dem System gut geht oder nicht, sondern Daten bereitzustellen, um dynamisch während des Betriebs stets einen Einblick in den Zustand des Systems zu haben.

Die drei primären Datenquellen für Observability sind dabei

• Log-Einträge,
• Metriken und
• Traces,

die unser System erzeugt und die zentral gesammelt und ausgewertet werden. Die beiden Themen Logging und Metriken habe ich bereits 2017 in „Logging und Metriken in verteilten Systemen“ vorgestellt.

In diesem Artikel wollen wir uns deshalb noch mit dem Thema Tracing befassen. Hierzu betrachten wir zuerst, was ein Trace überhaupt ist, und sehen uns anschließend an einem konkreten Beispiel an, wie eine Umsetzung für Java-Anwendungen aussehen kann.

Trace

Mit Traces, wortwörtlich übersetzt Spuren, ist es möglich aufzuzeichnen, was passiert, wenn unser System Anfragen abarbeitet. Jeder Trace besitzt eine ID, um diesen eindeutig identifizieren zu können, und einen oder mehrere Spans. Ein Span bildet dabei einen konkreten Arbeitsschritt ab und merkt sich dessen Anfangs- und Endzeitpunkt. Weiterhin können beliebige Attribute an einen Span gehängt werden.

Wird innerhalb eines laufenden Spans ein neuer Arbeitsschritt gestartet, wird auch ein neuer Span erzeugt. Dieser erhält jedoch einen Verweis auf den Span, durch den er erzeugt wurde. Somit entsteht innerhalb eines Trace eine Baumstruktur von Spans.

Da die Erzeugung von Spans einen gewissen Overhead mitbringt, es müssen beispielsweise Start- und Endzeitpunkt ermittelt werden und auch das Erzeugen der Attribute kann teuer sein, enthält ein Trace noch die Information, ob dieser überhaupt aufgezeichnet werden soll.

Komponenten

Wie wir im nächsten Kapitel noch sehen werden, steht uns eine Vielzahl an Lösungen für Tracing zur Verfügung. Und auch wenn diese sich im Detail stark unterscheiden können, ist der schematische Aufbau fast immer identisch (s. Abb. 1).

Innerhalb unserer Anwendung nutzen wir eine Clientbibliothek, um Traces und Spans zu erzeugen und anzureichen. Die meisten Lösungen unterstützen neben diesem manuellen Ansatz zusätzlich auch die Möglichkeit, die Anwendung automatisch instrumentieren zu lassen. Dabei erkennt die Bibliothek automatisch relevante Teile der Anwendung, beispielsweise Controllermethoden oder Datenbankaufrufe, und erzeugt für diese automatisiert passende Spans. Für die JVM wird dabei zumeist ein Java-Agent genutzt.

Der Client ist meistens auch dafür verantwortlich, die aufgezeichneten Traces an den Tracing-Server zu senden. Manche Lösungen bieten hier als Optimierung noch einen zusätzlichen Agenten an. Dieser wird mit der Anwendung, oder auf dem Host bei containerisierten Anwendungen, deployt und erhält die Traces von der Anwendung. Anschließend überträgt dieser die Traces zum Tracing-Server. Der Vorteil ist, dass die Netzwerkverbindung von Anwendung und Agent schnell und zuverlässig ist und die Anwendung somit ihre Traces schnell und sicher übergeben kann. Zudem kann der Agent noch Performanceverbesserungen wie das Batchen von Traces durchführen.

Der Tracing-Server wiederum besteht auch aus mehreren Teilen. Der Collector ist der Teil des Servers, der die Traces vom Client entgegennimmt und anschließend in einer Datenbank ablegt. Neben dem Collector gibt es dann in der Regel noch ein API, um Traces abzufragen, und natürlich eine Benutzeroberfläche.

Anbieter

Durch die Relevanz des Themas ist über die letzten Jahre eine große Menge an Softwarelösungen für Tracing entstanden, zwischen denen wir heute wählen können. Mir ist hauptsächlich New Relic in Erinnerung geblieben, weil dies, vor mehr als acht Jahren, das erste Mal war, dass ich die Wasserfalldarstellung eines Trace gesehen habe. Ich war von der Menge der Informationen, die dadurch gewonnen werden konnte, buchstäblich erschlagen.

Neben New Relic gibt es mit Datadog, Dynatrace, Honeycomb und Instana weitere kommerzielle Closed-Source-Lösungen, die ich in meinen letzten Projekten gesehen habe. Alternativ kann auch eine der vielen Open-Source-Lösungen eingesetzt werden. Neben den vermutlich bekanntesten Lösungen Jaeger und Zipkin gibt es mit Elastic APM und SigNoz noch zwei weitere spannende Lösungen. Und auch die Apache Software Foundation hat mit Skywalking eine Lösung.

Bei der Auswahl einer konkreten Lösung sollten neben dem Preis das angebotene Feature-Set und die Qualität der Instrumentierung eine Rolle in der Evaluierung spielen. Das Feature-Set reicht dabei vom reinen Sammeln und Darstellen von Traces bis zu Lösungen, die das gesamte Observability-Spektrum, inklusive Logging und Metriken, abbilden. Bei der Instrumentierung sollte darauf geachtet werden, dass die in der Anwendung genutzten Bibliotheken unterstützt werden.

Die Menge der hier genannten Lösungen hat schlussendlich auch dazu geführt, dass es mit OpenTelemetry eine Initiative der Cloud Native Computing Foundation gibt, die herstellerneutrale Standards definiert und Clientbibliotheken entwickelt.

Beispielanwendung

Normalerweise versuche ich, die Beispiele für meine Artikel immer so minimal wie möglich zu halten. In diesem Falle ist dies jedoch nicht einfach, da wir schon etwas mehr brauchen, um Tracing vernünftig zeigen zu können. Der gesamte Code zum Beispiel ist bei GitHub zu finden.

Als Anwendungsfall verwaltet die Beispielanwendung Sessions. Im ersten Schritt wird eine neue Session erzeugt und mit einer generierten ID versehen. Anschließend können mehrere beliebige Schlüssel-Wert-Paare an diese gehängt werden. Zum Schluss kann die Session übermittelt werden. Dabei werden alle angehängten Paare noch einmal ausgegeben und die Session anschließend gelöscht. Das Gesamtsystem besteht dabei aus den vier in Abbildung 2 zu sehenden Komponenten.

Das Backend, eine Spring Boot-Anwendung, kapselt den Zugriff auf die Datenbank, in diesem Fall Redis, und bietet eine HTTP-basierte Schnittstelle, um eine Session zu erzeugen, Schlüssel-Wert-Paare anzuhängen und die Session zu übermitteln (s. Abb. 3). Die Session wird hierzu als Java-Map unter der Session-ID in der Datenbank abgelegt. Auch das Frontend basiert auf Spring Boot und liefert mittels Thymeleaf serverseitig generiertes HTML an den Browser aus und kommuniziert bei Bedarf mit dem Backend (s. Abb. 4).

Um die Traces etwas spannender zu gestalten, gibt es in beiden Anwendungen einen DelayGenerator, über den an vielen Stellen eine Pause von zufälliger Länge eingefügt wird.

Als letzte Komponente nutzen wir hier Jaeger als Backend für unsere Traces. Um das Setup zu vereinfachen, nutzen wir hierzu das von Jaeger selber bereitgestellte all-in-one Docker Image, welches wir über Docker Compose (s. Listing 1) starten.

version: "3"
services:

    redis:
        image: "redis:7.0.2"
        ports:
            - "6379:6379"

    jaeger:
        image: "jaegertracing/all-in-one:1.35.1"
        environment:
            COLLECTOR_OTLP_ENABLED: "true"
            COLLECTOR_ZIPKIN_HOST_PORT: ":9411"
        ports:
            - "4317:4317"
            - "4318:4318"
            - "9411:9411"
            - "14250:14250"
            - "16686:16686"

Wir erlauben hierbei die Übermittlung von Traces im OpenTelemetry- und Zipkin-Format und öffnen die hierfür benötigten Ports, sowie den Port für die API und die grafische Oberfläche.

Backend-Tracing

Damit unser Backend Traces erzeugt, nutzen wir den von OpenTelemetry zur Verfügung gestellten Java-Agenten. Dieser wird beim Start der Anwendung mit angegeben und kann durch Umgebungsvariablen konfiguriert werden (s. Listing 2).

# OTEL agent configuration
export OTEL_SERVICE_NAME=backend
export OTEL_TRACES_EXPORTER=jaeger
export OTEL_METRICS_EXPORTER=none

# start application
java \
    -javaagent:../opentelemetry-javaagent.jar \
    -jar target/apm-example-backend.jar

Nachdem die Anwendung erfolgreich gestartet ist, können wir mit curl eine Session erzeugen, ändern und übermitteln (s. Listing 3). Anschließend rufen wir die Oberfläche von Jaeger unter http://localhost:16686 auf, wählen als Service backend aus und drücken auf den Find Traces-Button. Anschließend zeigt uns Jaeger (s. Abb. 5) eine Liste aller Traces unseres Backend an.

$ curl \
    -X POST localhost:9080/sessions
> ef86e474-e70c-4c16-8b65-104ca529eb5e

$ curl \
    -X PUT localhost:9080/sessions/ef86e474-e70c-4c16-8b65-104ca529eb5e \
    -H "Content-Type: application/json" \
    -d '{"a": "123", "b": "456"}'

$ curl \
    -X PUT localhost:9080/sessions/ef86e474-e70c-4c16-8b65-104ca529eb5e \
    -H "Content-Type: application/json" \
    -d '{"a": "Michael", "c": "123"}'

$ curl \
    -X DELETE localhost:9080/sessions/ef86e474-e70c-4c16-8b65-104ca529eb5e
> {"a":"Michael","b":"456","c":"123"}

Von hier aus können wir jetzt noch in einen konkreten Trace springen und erhalten weitere Details (s. Abb. 6). Wir sehen hier, dass unser Trace aus einem Root-Span besteht, welcher in Summe 1,59 Sekunden gedauert hat. Dieser wiederum hat einen Kind- Span, der den Aufruf der Spring-Controller-Methode abbildet mit identischer Dauer. Unsere komplette Antwortzeit wurde also vom Controller und dessen Aufrufen verbraucht.

Unterhalb des Controller-Spans sind noch vier weitere Spans zu sehen, die mit GET oder SET beschriftet sind. Der erste Span zu SET ist zudem noch detaillierter aufgeklappt. An den beiden Tags db.statement und db.system lässt sich erahnen, dass dieser Span einen SET-Aufruf zu Redis abbildet. Wir sehen also, dass unser Trace insgesamt vier Aufrufe an Redis produziert hat. Diese vier sind dabei stets innerhalb von wenigen Millisekunden erledigt gewesen. Die Zeit muss also in unserer Anwendung verbraucht worden sein.

Der OpenTelemetry Instrumentation Agent hat den Servletrequest, Spring-Controller-Methoden und Redis-Aufrufe bereits automatisch erkannt und hierzu automatisch einen neuen Span erzeugt, ohne dass wir etwas tun mussten. Möchten wir Spans für andere Komponenten in unserer Anwendung haben, können wir die OpenTelemetry-Clientbibliothek als Abhängigkeit hinzufügen und entsprechende Methoden beispielsweise mit @WithSpan annotieren. Anschließend sieht die Darstellung für denselben Trace wie in Abbildung 7 aus. Hier lässt sich jetzt schon sehr gut erkennen, wie der Fluss durch das Backend war und wodurch die Dauer entstanden ist.

Frontend-Tracing

Als Nächstes starten wir auch das Frontend. Natürlich wieder mit aktiviertem OpenTelemetry-Agenten. Nachdem wir über dieses, erreichbar unter http://localhost:8080, auch eine Session erzeugt, geändert und übermittelt haben, springen wir wieder zu Jaeger und suchen dieses Mal nach Traces für das frontend und öffnen die Details zu einem dieser Traces (s. Abb. 8).

Wir sehen nun, dass sich unser Trace über beide Anwendungen erstreckt. Diese Ansicht ist vor allem praktisch, um uns im Falle eines Performanzproblems zu zeigen, wo die meiste Zeit verbraucht wird.

Damit sich unser Trace über beide Anwendungen erstrecken kann, muss erkannt werden, zu welchem Frontend-Trace der Request, den das Backend abarbeitet hat, gehört. Hierzu wird das Konzept der Context Propagation genutzt. Dabei übermittelt das Frontend einen Context, bestehend aus Trace ID, Span ID und Flags, direkt beim Aufruf mit an das Backend. Im Falle von HTTP-Aufrufen wird hierzu häufig b3-propagation von Zipkin oder im Falle von OpenTelemetry die Trace Context Recommendation des W3C genutzt.

Natürlich funktioniert die Context Propagation auch mit anderen Technologien, nur die konkrete Art, wie der eigentliche Context übergeben wird, ist unterschiedlich, vor allem, wenn die Technologie keine Metadaten für den übertragenen Payload vorsieht.